diff --git a/lib/RequestLogger.js b/lib/RequestLogger.js index 679d627..cb51681 100644 --- a/lib/RequestLogger.js +++ b/lib/RequestLogger.js @@ -423,35 +423,12 @@ class RequestLogger { ); return; } - const fields = objectCopy({}, this.fields, logFields || {}); - const endFlag = isEnd || false; - /* - * using Date.now() as it's faster than new Date(). logstash component - * uses this field to generate ISO 8601 timestamp - */ - if (fields.time === undefined) { - fields.time = Date.now(); - } - - // eslint-disable-next-line camelcase - fields.req_id = serializeUids(this.uids); - if (endFlag) { - if (this.elapsedTime !== null) { - // reset elapsedTime to avoid an infinite recursion - // while logging the error - this.elapsedTime = null; - this.error('RequestLogger.end() has been called more than once'); - } - this.elapsedTime = process.hrtime(this.startTime); - // eslint-disable-next-line camelcase - fields.elapsed_ms = this.elapsedTime[0] * 1000 - + this.elapsedTime[1] / 1000000; - } const logEntry = { level, - fields, msg, + logFields, + isEnd: isEnd || false, }; this.entries.push(logEntry); @@ -459,46 +436,61 @@ class RequestLogger { this.entries.forEach(entry => { this.doLogIO(entry); }); - this.entries = []; + this.entries = []; // Flush buffer after dumping } else if (LogLevel.shouldLog(level, this.logLevel)) { this.doLogIO(logEntry); } } /** - * This function transmits a log entry to the configured bunyan logger - * instance. This way, we can rely on bunyan for actual logging operations, - * and logging multiplexing, instead of managing that ourselves. + * This function assembles the final log object from a buffered entry + * and transmits it to the underlying bunyan logger instance for I/O. * * @private * - * @param {object} logEntry - The Logging entry to be passed to - * bunyan - * @param {string} logEntry.msg - The message to be logged - * @param {object} logEntry.fields - The data fields to associate to the - * log entry. - * + * @param {object} logEntry - The Logging entry to be processed. + * @param {string} logEntry.msg - The message to be logged * @returns {undefined} */ doLogIO(logEntry) { + const fields = objectCopy({}, this.fields, logEntry.logFields || {}); + + if (fields.time === undefined) { + fields.time = Date.now(); + } + + // eslint-disable-next-line camelcase + fields.req_id = serializeUids(this.uids); + if (logEntry.isEnd) { + if (this.elapsedTime !== null) { + // reset elapsedTime to avoid an infinite recursion + // while logging the error + this.elapsedTime = null; + this.error('RequestLogger.end() has been called more than once'); + } + this.elapsedTime = process.hrtime(this.startTime); + // eslint-disable-next-line camelcase + fields.elapsed_ms = this.elapsedTime[0] * 1000 + + this.elapsedTime[1] / 1000000; + } switch (logEntry.level) { case 'trace': - this.sLogger.trace(logEntry.fields, logEntry.msg); + this.sLogger.trace(fields, logEntry.msg); break; case 'debug': - this.sLogger.debug(logEntry.fields, logEntry.msg); + this.sLogger.debug(fields, logEntry.msg); break; case 'info': - this.sLogger.info(logEntry.fields, logEntry.msg); + this.sLogger.info(fields, logEntry.msg); break; case 'warn': - this.sLogger.warn(logEntry.fields, logEntry.msg); + this.sLogger.warn(fields, logEntry.msg); break; case 'error': - this.sLogger.error(logEntry.fields, logEntry.msg); + this.sLogger.error(fields, logEntry.msg); break; case 'fatal': - this.sLogger.fatal(logEntry.fields, logEntry.msg); + this.sLogger.fatal(fields, logEntry.msg); break; default: throw new Error(`Unexpected log level: ${logEntry.level}`); diff --git a/lib/SimpleLogger.js b/lib/SimpleLogger.js index 6755430..46e3e86 100644 --- a/lib/SimpleLogger.js +++ b/lib/SimpleLogger.js @@ -1,6 +1,7 @@ const os = require('os'); const safeJSONStringify = require('safe-json-stringify'); const fastJSONStringify = require('fast-safe-stringify'); +const LogLevel = require('./LogLevel'); /* * This function safely stringifies JSON. If an exception occcurs (due to @@ -64,15 +65,18 @@ class SimpleLogger { logMsg = message; logFields = fields || {}; } - // TODO - Protect these fields from being overwritten - logFields.level = level; - logFields.message = logMsg; - logFields.hostname = this.hostname; - logFields.pid = process.pid; - const safeString = safeStringify(logFields); - this.streams.forEach(s => s.stream - .write(`${safeString}\n`)); + this.streams.forEach(s => { + if (LogLevel.shouldLog(level, s.level)) { + const finalLogFields = { ...logFields }; + finalLogFields.level = level; + finalLogFields.message = logMsg; + finalLogFields.hostname = this.hostname; + finalLogFields.pid = process.pid; + const safeString = safeStringify(finalLogFields); + s.stream.write(`${safeString}\n`); + } + }); } info(fields, message) { diff --git a/package.json b/package.json index 57c97ae..0748614 100644 --- a/package.json +++ b/package.json @@ -3,7 +3,7 @@ "engines": { "node": ">=20" }, - "version": "8.2.2", + "version": "8.2.3", "description": "An efficient raw JSON logging library aimed at micro-services architectures.", "main": "index.js", "scripts": {