Enhance logging in API calls and request/response middleware with sensitive data filtering and compact format
All checks were successful
Build & Push Docker Image / build (push) Successful in 6m28s
All checks were successful
Build & Push Docker Image / build (push) Successful in 6m28s
This commit is contained in:
@@ -18,19 +18,75 @@ function buildUrl(apiCall, params = {}) {
|
|||||||
|
|
||||||
async function apiCall(apiCallName, params = {}, xmlBody = null) {
|
async function apiCall(apiCallName, params = {}, xmlBody = null) {
|
||||||
const url = buildUrl(apiCallName, params);
|
const url = buildUrl(apiCallName, params);
|
||||||
|
// Logging: compact key=value style, filter sensitive params
|
||||||
|
function formatUTC(d) {
|
||||||
|
const pad = n => String(n).padStart(2, '0');
|
||||||
|
const Y = d.getUTCFullYear();
|
||||||
|
const M = pad(d.getUTCMonth() + 1);
|
||||||
|
const D = pad(d.getUTCDate());
|
||||||
|
const h = pad(d.getUTCHours());
|
||||||
|
const m = pad(d.getUTCMinutes());
|
||||||
|
const s = pad(d.getUTCSeconds());
|
||||||
|
return `${Y}-${M}-${D} ${h}:${m}:${s} UTC`;
|
||||||
|
}
|
||||||
|
|
||||||
|
const SENSITIVE_KEYS = [/pass/i, /pwd/i, /password/i, /token/i, /jwt/i, /secret/i, /authorization/i, /auth/i, /api[_-]?key/i];
|
||||||
|
const isSensitive = key => SENSITIVE_KEYS.some(rx => rx.test(key));
|
||||||
|
|
||||||
|
function sanitizeParams(p) {
|
||||||
|
try {
|
||||||
|
const out = [];
|
||||||
|
for (const k of Object.keys(p || {})) {
|
||||||
|
if (k.toLowerCase() === 'checksum') continue; // never log checksum
|
||||||
|
if (isSensitive(k)) {
|
||||||
|
out.push(`${k}=[FILTERED]`);
|
||||||
|
} else {
|
||||||
|
let v = p[k];
|
||||||
|
if (typeof v === 'string' && v.length > 100) v = v.slice(0, 100) + '...[truncated]';
|
||||||
|
out.push(`${k}=${String(v)}`);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
return out.join('&') || '-';
|
||||||
|
} catch (e) {
|
||||||
|
return '-';
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
const start = Date.now();
|
||||||
try {
|
try {
|
||||||
const fetchOptions = xmlBody
|
const fetchOptions = xmlBody
|
||||||
? { method: 'POST', headers: { 'Content-Type': 'application/xml' }, body: xmlBody }
|
? { method: 'POST', headers: { 'Content-Type': 'application/xml' }, body: xmlBody }
|
||||||
: {};
|
: {};
|
||||||
const response = await fetch(url, fetchOptions);
|
const response = await fetch(url, fetchOptions);
|
||||||
|
const duration = Date.now() - start;
|
||||||
const xml = await response.text();
|
const xml = await response.text();
|
||||||
const result = await xml2js.parseStringPromise(xml, {
|
const result = await xml2js.parseStringPromise(xml, {
|
||||||
explicitArray: false,
|
explicitArray: false,
|
||||||
trim: true,
|
trim: true,
|
||||||
});
|
});
|
||||||
|
|
||||||
|
// Compact log: time=... method=GET path=getMeetings format=xml status=200 duration=12.34 bbb_returncode=SUCCESS params=meetingID=123
|
||||||
|
try {
|
||||||
|
const tokens = [];
|
||||||
|
tokens.push(`time=${formatUTC(new Date())}`);
|
||||||
|
tokens.push(`method=${xmlBody ? 'POST' : 'GET'}`);
|
||||||
|
tokens.push(`path=${apiCallName}`);
|
||||||
|
tokens.push(`format=xml`);
|
||||||
|
tokens.push(`status=${response.status}`);
|
||||||
|
tokens.push(`duration=${(duration).toFixed(2)}`);
|
||||||
|
const bbbCode = result && result.response && result.response.returncode ? result.response.returncode : '-';
|
||||||
|
tokens.push(`bbb_returncode=${bbbCode}`);
|
||||||
|
const safeParams = sanitizeParams(params);
|
||||||
|
tokens.push(`params=${safeParams}`);
|
||||||
|
console.info(tokens.join(' '));
|
||||||
|
} catch (e) {
|
||||||
|
// ignore logging errors
|
||||||
|
}
|
||||||
|
|
||||||
return result.response;
|
return result.response;
|
||||||
} catch (error) {
|
} catch (error) {
|
||||||
console.error(`BBB API error (${apiCallName}):`, error.message);
|
const duration = Date.now() - start;
|
||||||
|
console.error(`BBB API error (${apiCallName}) status=error duration=${(duration).toFixed(2)} err=${error.message}`);
|
||||||
throw error;
|
throw error;
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -43,6 +43,17 @@ function filterHeaders(headers) {
|
|||||||
return out;
|
return out;
|
||||||
}
|
}
|
||||||
|
|
||||||
|
function formatUTC(d) {
|
||||||
|
const pad = n => String(n).padStart(2, '0');
|
||||||
|
const Y = d.getUTCFullYear();
|
||||||
|
const M = pad(d.getUTCMonth() + 1);
|
||||||
|
const D = pad(d.getUTCDate());
|
||||||
|
const h = pad(d.getUTCHours());
|
||||||
|
const m = pad(d.getUTCMinutes());
|
||||||
|
const s = pad(d.getUTCSeconds());
|
||||||
|
return `${Y}-${M}-${D} ${h}:${m}:${s} UTC`;
|
||||||
|
}
|
||||||
|
|
||||||
export default function requestResponseLogger(req, res, next) {
|
export default function requestResponseLogger(req, res, next) {
|
||||||
try {
|
try {
|
||||||
const start = Date.now();
|
const start = Date.now();
|
||||||
@@ -73,51 +84,28 @@ export default function requestResponseLogger(req, res, next) {
|
|||||||
|
|
||||||
res.on('finish', () => {
|
res.on('finish', () => {
|
||||||
try {
|
try {
|
||||||
const duration = Date.now() - start;
|
const duration = Date.now() - start; // ms
|
||||||
const resHeaders = filterHeaders(res.getHeaders ? res.getHeaders() : {});
|
|
||||||
|
|
||||||
let loggedResponseBody = null;
|
|
||||||
const resContentType = (res.getHeader && (res.getHeader('content-type') || '')).toString().toLowerCase();
|
const resContentType = (res.getHeader && (res.getHeader('content-type') || '')).toString().toLowerCase();
|
||||||
if (responseBody === undefined) {
|
|
||||||
loggedResponseBody = '[none-captured]';
|
|
||||||
} else if (resContentType.includes('application/json')) {
|
|
||||||
try {
|
|
||||||
const parsed = typeof responseBody === 'string' ? JSON.parse(responseBody) : responseBody;
|
|
||||||
loggedResponseBody = filterValue(null, parsed);
|
|
||||||
} catch (e) {
|
|
||||||
loggedResponseBody = typeof responseBody === 'string' ? (responseBody.length > 1000 ? responseBody.slice(0, 1000) + '...[truncated]' : responseBody) : util.inspect(responseBody);
|
|
||||||
}
|
|
||||||
} else if (resContentType.includes('text/') || resContentType.includes('application/xml')) {
|
|
||||||
const asStr = typeof responseBody === 'string' ? responseBody : util.inspect(responseBody);
|
|
||||||
loggedResponseBody = asStr.length > 1000 ? asStr.slice(0, 1000) + '...[truncated]' : asStr;
|
|
||||||
} else {
|
|
||||||
loggedResponseBody = '[not-logged-due-to-content-type]';
|
|
||||||
}
|
|
||||||
|
|
||||||
const log = {
|
// Compact key=value log (no bodies, sensitive data filtered)
|
||||||
time: new Date().toISOString(),
|
const tokens = [];
|
||||||
ip,
|
tokens.push(`time=${formatUTC(new Date())}`);
|
||||||
method,
|
tokens.push(`method=${method}`);
|
||||||
url: originalUrl,
|
tokens.push(`path=${originalUrl.replace(/\s/g, '%20')}`);
|
||||||
status: res.statusCode,
|
const fmt = resContentType.includes('json') ? 'json' : (resContentType.includes('html') ? 'html' : 'other');
|
||||||
duration_ms: duration,
|
tokens.push(`format=${fmt}`);
|
||||||
request: {
|
tokens.push(`status=${res.statusCode}`);
|
||||||
headers: reqHeaders,
|
tokens.push(`duration=${(duration).toFixed(2)}`);
|
||||||
query: filterValue(null, req.query || {}),
|
|
||||||
body: reqBody,
|
|
||||||
},
|
|
||||||
response: {
|
|
||||||
headers: resHeaders,
|
|
||||||
body: loggedResponseBody,
|
|
||||||
},
|
|
||||||
};
|
|
||||||
|
|
||||||
// Output as single-line JSON for log aggregation
|
// Optional: content-length if available
|
||||||
try {
|
try {
|
||||||
console.info(JSON.stringify(log));
|
const cl = res.getHeader && (res.getHeader('content-length') || res.getHeader('Content-Length'));
|
||||||
|
if (cl) tokens.push(`length=${String(cl)}`);
|
||||||
} catch (e) {
|
} catch (e) {
|
||||||
console.info('LOG_ERROR', util.inspect(log));
|
// ignore
|
||||||
}
|
}
|
||||||
|
|
||||||
|
console.info(tokens.join(' '));
|
||||||
} catch (e) {
|
} catch (e) {
|
||||||
console.error('RequestLogger error:', e);
|
console.error('RequestLogger error:', e);
|
||||||
}
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user