feat: structured logging (JSON) (#5118)

This commit is contained in:
Cassandra 2024-09-24 11:51:21 +02:00 committed by GitHub
parent dd75890364
commit b287a25de7
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
27 changed files with 186 additions and 239 deletions

View file

@ -1,5 +1,6 @@
let url = require("url");
let MemoryCache = require("./memory-cache");
const { log } = require("../../../src/util");
let t = {
ms: 1,
@ -90,24 +91,6 @@ function ApiCache() {
instances.push(this);
this.id = instances.length;
/**
* Logs a message to the console if the `DEBUG` environment variable is set.
* @param {string} a The first argument to log.
* @param {string} b The second argument to log.
* @param {string} c The third argument to log.
* @param {string} d The fourth argument to log, and so on... (optional)
*
* Generated by Trelent
*/
function debug(a, b, c, d) {
let arr = ["\x1b[36m[apicache]\x1b[0m", a, b, c, d].filter(function (arg) {
return arg !== undefined;
});
let debugEnv = process.env.DEBUG && process.env.DEBUG.split(",").indexOf("apicache") !== -1;
return (globalOptions.debug || debugEnv) && console.log.apply(null, arr);
}
/**
* Returns true if the given request and response should be logged.
* @param {Object} request The HTTP request object.
@ -146,7 +129,7 @@ function ApiCache() {
let groupName = req.apicacheGroup;
if (groupName) {
debug("group detected \"" + groupName + "\"");
log.debug("apicache", `group detected "${groupName}"`);
let group = (index.groups[groupName] = index.groups[groupName] || []);
group.unshift(key);
}
@ -212,7 +195,7 @@ function ApiCache() {
redis.hset(key, "duration", duration);
redis.expire(key, duration / 1000, expireCallback || function () {});
} catch (err) {
debug("[apicache] error in redis.hset()");
log.debug("apicache", `error in redis.hset(): ${err}`);
}
} else {
memCache.add(key, value, duration, expireCallback);
@ -320,10 +303,10 @@ function ApiCache() {
// display log entry
let elapsed = new Date() - req.apicacheTimer;
debug("adding cache entry for \"" + key + "\" @ " + strDuration, logDuration(elapsed));
debug("_apicache.headers: ", res._apicache.headers);
debug("res.getHeaders(): ", getSafeHeaders(res));
debug("cacheObject: ", cacheObject);
log.debug("apicache", `adding cache entry for "${key}" @ ${strDuration} ${logDuration(elapsed)}`);
log.debug("apicache", `_apicache.headers: ${JSON.stringify(res._apicache.headers)}`);
log.debug("apicache", `res.getHeaders(): ${JSON.stringify(getSafeHeaders(res))}`);
log.debug("apicache", `cacheObject: ${JSON.stringify(cacheObject)}`);
}
}
@ -402,10 +385,10 @@ function ApiCache() {
let redis = globalOptions.redisClient;
if (group) {
debug("clearing group \"" + target + "\"");
log.debug("apicache", `clearing group "${target}"`);
group.forEach(function (key) {
debug("clearing cached entry for \"" + key + "\"");
log.debug("apicache", `clearing cached entry for "${key}"`);
clearTimeout(timers[key]);
delete timers[key];
if (!globalOptions.redisClient) {
@ -414,7 +397,7 @@ function ApiCache() {
try {
redis.del(key);
} catch (err) {
console.log("[apicache] error in redis.del(\"" + key + "\")");
log.info("apicache", "error in redis.del(\"" + key + "\")");
}
}
index.all = index.all.filter(doesntMatch(key));
@ -422,7 +405,7 @@ function ApiCache() {
delete index.groups[target];
} else if (target) {
debug("clearing " + (isAutomatic ? "expired" : "cached") + " entry for \"" + target + "\"");
log.debug("apicache", `clearing ${isAutomatic ? "expired" : "cached"} entry for "${target}"`);
clearTimeout(timers[target]);
delete timers[target];
// clear actual cached entry
@ -432,7 +415,7 @@ function ApiCache() {
try {
redis.del(target);
} catch (err) {
console.log("[apicache] error in redis.del(\"" + target + "\")");
log.error("apicache", "error in redis.del(\"" + target + "\")");
}
}
@ -449,7 +432,7 @@ function ApiCache() {
}
});
} else {
debug("clearing entire index");
log.debug("apicache", "clearing entire index");
if (!redis) {
memCache.clear();
@ -461,7 +444,7 @@ function ApiCache() {
try {
redis.del(key);
} catch (err) {
console.log("[apicache] error in redis.del(\"" + key + "\")");
log.error("apicache", `error in redis.del("${key}"): ${err}`);
}
});
}
@ -528,7 +511,7 @@ function ApiCache() {
/**
* Get index of a group
* @param {string} group
* @param {string} group
* @returns {number}
*/
this.getIndex = function (group) {
@ -543,9 +526,9 @@ function ApiCache() {
* Express middleware
* @param {(string|number)} strDuration Duration to cache responses
* for.
* @param {function(Object, Object):boolean} middlewareToggle
* @param {function(Object, Object):boolean} middlewareToggle
* @param {Object} localOptions Options for APICache
* @returns
* @returns
*/
this.middleware = function cache(strDuration, middlewareToggle, localOptions) {
let duration = instance.getDuration(strDuration);
@ -752,7 +735,7 @@ function ApiCache() {
*/
let cache = function (req, res, next) {
function bypass() {
debug("bypass detected, skipping cache.");
log.debug("apicache", "bypass detected, skipping cache.");
return next();
}
@ -805,7 +788,7 @@ function ApiCache() {
// send if cache hit from memory-cache
if (cached) {
let elapsed = new Date() - req.apicacheTimer;
debug("sending cached (memory-cache) version of", key, logDuration(elapsed));
log.debug("apicache", `sending cached (memory-cache) version of ${key} ${logDuration(elapsed)}`);
perf.hit(key);
return sendCachedResponse(req, res, cached, middlewareToggle, next, duration);
@ -817,7 +800,7 @@ function ApiCache() {
redis.hgetall(key, function (err, obj) {
if (!err && obj && obj.response) {
let elapsed = new Date() - req.apicacheTimer;
debug("sending cached (redis) version of", key, logDuration(elapsed));
log.debug("apicache", "sending cached (redis) version of "+ key+" "+ logDuration(elapsed));
perf.hit(key);
return sendCachedResponse(
@ -859,7 +842,7 @@ function ApiCache() {
/**
* Process options
* @param {Object} options
* @param {Object} options
* @returns {Object}
*/
this.options = function (options) {
@ -873,7 +856,7 @@ function ApiCache() {
}
if (globalOptions.trackPerformance) {
debug("WARNING: using trackPerformance flag can cause high memory usage!");
log.debug("apicache", "WARNING: using trackPerformance flag can cause high memory usage!");
}
return this;