Compare commits

..

1 Commits

Author SHA1 Message Date
Rahul Padigela 0ec8c532c4 perf: defer log processing if not log level 2016-06-16 16:34:20 -07:00
31 changed files with 598 additions and 1413 deletions

View File

@ -1 +1,13 @@
{ "extends": "scality" }
{
"extends": "airbnb",
"env": {
"node": true,
"mocha": true
},
"rules": {
"indent": [2,4],
"no-multi-spaces": [2, { exceptions: { "SwitchCase": true, "CallExpression": true } } ],
"valid-jsdoc": 2,
"strict": 0
}
}

View File

@ -1,31 +0,0 @@
name: Tests
on:
push:
branches-ignore:
- development/**
- q/*/**
jobs:
tests:
runs-on: ubuntu-latest
steps:
- name: Checkokut
uses: actions/checkout@v4
- name: Install deps
run: sudo apt-get update -q
- uses: actions/setup-node@v4
with:
node-version: '16'
- name: Install Yarn
run: npm install -g yarn
- name: install dependencies
run: yarn install --frozen-lockfile
- name: run lint
run: echo "linter is disabled temporarily ()" || yarn run --silent lint -- --max-warnings 0
- name: run lint_md
run: yarn --silent lint_md
- name: run test
run: yarn test
- name: run coverage
run: yarn coverage

View File

@ -41,10 +41,9 @@ as it means that whenever the errors happen, depending on your log level, you
might have already lost quite a bit of priceless information about the error
encountered, and the code path the request went through. To address this, we
offer multiple features:
* [Request ID namespacing](###request-id-namespacing)
* [Request unit Logs](###request-unit-logs)
* [Request ID namespacing](###request-id-namespacing)
* [Request unit Logs](###request-unit-logs)
### Request ID namespacing
Usually, in networked systems, it is considered good practice to generate an
@ -88,3 +87,5 @@ error (or higher level logging operation) is logged before the log context is
freed, then the full set of buffered logging messages is freed, not taking
any logging resources for the log entries not considered 'useless' by a given
log level configuration.

View File

@ -1,5 +1,6 @@
# WereLogs
[![CircleCI][badgepub]](https://circleci.com/gh/scality/werelogs)
[![Scality CI][badgepriv]](http://ci.ironmann.io/gh/scality/werelogs)
This repository provides a NodeJS Library that aims to be an efficient logging
@ -18,8 +19,7 @@ https://github.com/scality/Guidelines/blob/master/CONTRIBUTING.md).
In order to install WereLogs, you can use NPM with github's HTTP url, and save
it in your own package.json:
```sh
```
$> npm i --save scality/werelogs
```
@ -157,3 +157,11 @@ In order to find out the known issues, it is advised to take a look at the
[project's github page](http://github.com/scality/werelogs). There, you should
be able to find the issues, tagged with the releases they are impacting,
whether they're open or closed.
## Contributing
The contributing rules for this project are defined in the associated
CONTRIBUTING.md file.
[badgepub]: https://circleci.com/gh/scality/werelogs.svg?style=svg
[badgepriv]: http://ci.ironmann.io/gh/scality/werelogs.svg?style=svg&circle-token=a946e81ad65b99814403b5e57f017d9ecbe93f0a

23
circle.yml Normal file
View File

@ -0,0 +1,23 @@
general:
branches:
ignore:
- /^ultron\/.*/ # Ignore ultron/* branches
artifacts:
- coverage/
- doc/
machine:
node:
version: 4.1.0
test:
override:
- npm run lint_md
- npm run lint
- npm run gendoc
- npm run coverage
# running ft_test packs werelogs and installs it + deps into
# tests/functional. Pack is like publishing werelogs in a local tgz
# archive that can be installed.
# This step shall ensure that no issue is encountered when installing
# the package, and allows to functionally test werelogs.
- npm run ft_test

65
index.d.ts vendored
View File

@ -1,65 +0,0 @@
interface WerelogsConfigOptions {
level?: 'trace' | 'debug' | 'info' | 'warn' | 'error' | 'fatal';
dump?: 'trace' | 'debug' | 'info' | 'warn' | 'error' | 'fatal';
streams?: object[];
}
declare class WerelogsConfig {
constructor(config?: WerelogsConfigOptions);
reset(): WerelogsConfig;
update(config: WerelogsConfig): WerelogsConfig;
logger: any;
level: 'trace' | 'debug' | 'info' | 'warn' | 'error' | 'fatal';
dump: 'trace' | 'debug' | 'info' | 'warn' | 'error' | 'fatal';
end: 'trace' | 'debug' | 'info' | 'warn' | 'error' | 'fatal';
}
interface LogDictionary {
httpMethod?: string;
httpURL?: string;
[field: string]: any;
}
declare module 'werelogs' {
export class RequestLogger {
constructor(
logger: any,
logLevel: string,
dumpThreshold: string,
endLevel: string,
uids?: string|Array<string>
);
getUids(): Array<string>;
getSerializedUids(): string;
addDefaultFields(fields: LogDictionary): LogDictionary;
trace(msg: string, data?: LogDictionary): void;
debug(msg: string, data?: LogDictionary): void;
info(msg: string, data?: LogDictionary): void;
warn(msg: string, data?: LogDictionary): void;
error(msg: string, data?: LogDictionary): void;
fatal(msg: string, data?: LogDictionary): void;
end(msg: string, data?: LogDictionary): void;
errorEnd(msg: string, data?:LogDictionary): void;
}
export class Logger {
name: string;
constructor(name: string);
newRequestLogger(uids?: string|Array<string>): RequestLogger;
newRequestLoggerFromSerializedUids(uids: string): RequestLogger;
trace(msg: string, data?: LogDictionary): void;
debug(msg: string, data?: LogDictionary): void;
info(msg: string, data?: LogDictionary): void;
warn(msg: string, data?: LogDictionary): void;
error(msg: string, data?: LogDictionary): void;
fatal(msg: string, data?: LogDictionary): void;
}
export function configure(config: WerelogsConfigOptions): void;
export class API {
constructor(config: WerelogsConfigOptions);
reconfigure(config: WerelogsConfigOptions): void;
Logger: Logger;
}
}

View File

@ -1,51 +1 @@
const API = require('./lib/api.js');
const stderrUtils = require('./lib/stderrUtils');
/*
* For convenience purposes, we provide an already instanciated API; so that
* old uses of the imported Logger class can be kept as-is. For quick logging,
* this also provides a hassle-free way to log using werelogs.
*/
const werelogs = new API();
module.exports = {
Logger: werelogs.Logger,
configure: werelogs.reconfigure.bind(werelogs),
Werelogs: API,
/**
* Timestamp logs going to stderr
*
* @example <caption>Simplest usage</caption>
* ```
* const { stderrUtils } = require('werelogs');
* stderrUtils.catchAndTimestampStderr();
* ```
*
* @example <caption>Manage process exit</caption>
* ```
* const { stderrUtils } = require('werelogs');
* // set exitCode to null to keep process running on uncaughtException
* stderrUtils.catchAndTimestampStderr(undefined, null);
* // application init
* process.on('uncaughtException', (err) => {
* // custom handling, close connections, files
* this.worker.kill(); // or process.exit(1);
* });
* // Note you could use prependListener to execute your callback first
* // and then let stderrUtils exit the process.
* ```
*
* @example <caption>Custom listener</caption>
* ```
* const { stderrUtils } = require('werelogs');
* stderrUtils.catchAndTimestampWarning();
* // application init
* process.on('uncaughtException', (err, origin) => {
* stderrUtils.printErrorWithTimestamp(err, origin);
* // close and stop everything
* process.exit(1);
* });
* ```
*/
stderrUtils,
};
module.exports = require('./lib/Logger.js');

View File

@ -1,5 +1,5 @@
'use strict';
// eslint-disable-line strict
const LogLevel = require('./LogLevel.js');
const SimpleLogger = require('./SimpleLogger.js');
@ -15,31 +15,10 @@ class Config {
* This is the default constructor of the Config Object, and the only way
* to instanciate it (with default parameters).
*
* @param {object} conf - A configuration object for werelogs.
* @param {string} conf.level - The string name of the logging level
* ('trace', 'debug', 'info', 'warn',
* 'error' and 'fatal' in order of
* importance.)
* @param {string} conf.dump - The string name of the log dumping
* level ('trace', 'debug', 'info',
* 'warn', 'error' and 'fatal' in order
* of importance.)
* @param {object[]} conf.streams - The array of streams into which to
* log. This is an Array of objects
* which have a field named 'stream',
* which is writeable.
*
* @returns {undefined}
*/
constructor(conf) {
this.logLevel = 'info';
this.dumpThreshold = 'error';
this.endLevel = 'info';
this.streams = [{ level: 'trace', stream: process.stdout }];
this.simpleLogger = new SimpleLogger('werelogs', this.streams);
if (conf) {
this.update(conf);
}
constructor() {
this.reset();
}
/**
@ -71,10 +50,12 @@ class Config {
* ('trace', 'debug', 'info', 'warn',
* 'error' and 'fatal' in order of
* importance.)
* @param {object[]} config.streams - The array of streams into which to
* log. This is an Array of objects
* which have a field named 'stream',
* which is writeable.
* @param {object[]} config.streams - The array of streams into which to log.
* Their configuration is directly
* related to the expected bunyan
* streams array, for compatibility
* purposes (except that the 'level'
* field is not accounted for)
*
* @see [Bunyan's documentation]{@link
* https://github.com/trentm/node-bunyan/blob/master/README.md#streams} for
@ -89,50 +70,34 @@ class Config {
const checkedConfig = config || {};
if (Object.prototype.hasOwnProperty.call(checkedConfig, 'level')) {
if (checkedConfig.hasOwnProperty('level')) {
LogLevel.throwIfInvalid(checkedConfig.level);
}
if (Object.prototype.hasOwnProperty.call(checkedConfig, 'dump')) {
LogLevel.throwIfInvalid(checkedConfig.dump);
}
// for check log level vs. log dump level
const newLogLevel = checkedConfig.level || this.logLevel;
const newLogDumpLevel = checkedConfig.dump || this.dumpThreshold;
if (newLogDumpLevel
&& !LogLevel.shouldLog(newLogDumpLevel, newLogLevel)) {
throw new Error(
'Logging level should be at most logging dump level',
);
}
if (Object.prototype.hasOwnProperty.call(checkedConfig, 'level')) {
this.logLevel = checkedConfig.level;
}
if (Object.prototype.hasOwnProperty.call(checkedConfig, 'dump')) {
if (checkedConfig.hasOwnProperty('dump')) {
LogLevel.throwIfInvalid(checkedConfig.dump);
this.dumpThreshold = checkedConfig.dump;
}
if (Object.prototype.hasOwnProperty.call(checkedConfig, 'end')) {
if (checkedConfig.hasOwnProperty('end')) {
LogLevel.throwIfInvalid(checkedConfig.end);
this.endLevel = checkedConfig.end;
}
if (Object.prototype.hasOwnProperty.call(checkedConfig, 'streams')) {
if (checkedConfig.hasOwnProperty('streams')) {
if (!Array.isArray(checkedConfig.streams)) {
throw new TypeError('WereLogs config.streams must be an Array '
+ 'of Writeable Streams.');
throw new Error('WereLogs config.streams must be an Array of Writeable Streams.');
}
if (!checkedConfig.streams.length) {
throw new Error('Werelogs config.streams must contain at '
+ 'least one stream.');
throw new Error('Werelogs config.streams must contain at least one stream.');
}
this.streams = checkedConfig.streams.map(stream => {
stream.level = 'trace'; // eslint-disable-line no-param-reassign
this.streams = checkedConfig.streams.map((stream) => {
stream.level = 'trace';
return stream;
});
this.simpleLogger = new SimpleLogger('werelogs', this.streams);
this.simpleLogger = new SimpleLogger( 'werelogs', this.streams );
}
return this;
@ -188,4 +153,4 @@ class Config {
}
}
module.exports = Config;
module.exports = new Config();

View File

@ -1,5 +1,4 @@
// eslint-disable-line strict
'use strict';
const logLevels = [
'trace',
@ -19,15 +18,10 @@ const logLevels = [
*
* @throw {Error} A human-readable message that tells which log
* levels are supported.
* @throw {TypeError} A human-readable message indicating that the
* provided logging level was not a string
*
* @returns {undefined}
*/
function throwIfInvalid(level) {
if (typeof level !== 'string') {
throw new TypeError('Logging level should be a string');
}
if (logLevels.indexOf(level) === -1) {
throw new RangeError(`Invalid logging level: ${level} is neither`
+ ` ${logLevels.join(', ')}.`);

View File

@ -1,32 +1,52 @@
// eslint-disable-line strict
'use strict';
const LogLevel = require('./LogLevel.js');
const RequestLogger = require('./RequestLogger.js');
const { unserializeUids } = require('./Utils.js');
const unserializeUids = require('./Utils.js').unserializeUids;
const Config = require('./Config.js');
class Logger {
/**
* This is the constructor of the Logger class. It takes optional
* configuration parameters, that allow to modify its behavior.
*
* @param {Werelogs.Config} config - An instanciated Werelogs Config object
* @param {string} name - The name of the Logger. It can be found later on in
* the log entries.
*
* @param {string} name - The name of the Logger. It can be found later on
* in the log entries.
* @param {object} config - A configuration object for werelogs.
* @param {string} config.level - The string name of the logging level
* ('trace', 'debug', 'info', 'warn',
* 'error' and 'fatal' in order of
* importance.)
* @param {string} config.dump - The string name of the log dumping level
* ('trace', 'debug', 'info', 'warn',
* 'error' and 'fatal' in order of
* importance.)
* @param {object[]} config.streams - The array of streams into which to log.
* Their configuration is directly
* related to the expected bunyan
* streams array, for compatibility
* purposes (except that the 'level'
* field is not accounted for)
*
* @see [Bunyan's documentation]{@link
* https://github.com/trentm/node-bunyan/blob/master/README.md#streams} for
* a more detailed description of the streams array configuration.
*
* @returns {undefined}
*/
constructor(config, name) {
if (!(config instanceof Config)) {
throw new TypeError('Invalid parameter Type for "config".');
}
if (!(typeof name === 'string' || name instanceof String)) {
throw new TypeError('Invalid parameter Type for "name".');
}
this.config = config;
constructor(name, config) {
this.name = name;
Config.update(config);
}
setLevel(levelName) {
Config.update({ level: levelName });
}
setDumpThreshold(levelName) {
Config.update({ dump: levelName });
}
/**
@ -38,10 +58,10 @@ class Logger {
* @returns {RequestLogger} A Valid Request Logger
*/
newRequestLogger(uids) {
const rLog = new RequestLogger(this.config.logger,
this.config.level, this.config.dump,
this.config.end, uids);
rLog.addDefaultFields({ name: this.name });
const rLog = new RequestLogger(Config.logger,
Config.level, Config.dump, Config.end,
uids);
rLog.addDefaultFields({name: this.name});
return rLog;
}
@ -54,36 +74,34 @@ class Logger {
* @returns {RequestLogger} A Valid Request Logger
*/
newRequestLoggerFromSerializedUids(serializedUids) {
const rLog = new RequestLogger(this.config.logger,
this.config.level, this.config.dump,
this.config.end,
unserializeUids(serializedUids));
rLog.addDefaultFields({ name: this.name });
const rLog = new RequestLogger(Config.logger,
Config.level, Config.dump, Config.end,
unserializeUids(serializedUids));
rLog.addDefaultFields({name: this.name});
return rLog;
}
_doLog(levelName, msg, data) {
const sLogger = this.config.logger;
const finalData = { name: this.name, time: Date.now() };
if (!LogLevel.shouldLog(levelName, this.config.level)) {
const sLogger = Config.logger;
const finalData = { name: this.name };
if (!LogLevel.shouldLog(levelName, Config.level)) {
return;
}
if (data !== undefined && typeof data !== 'object') {
sLogger.fatal(
{
callparams: [msg, data],
'callparams': [ msg, data ],
},
'Werelogs API was mis-used.'
+ ' This development error should be fixed ASAP.',
);
+ ' This development error should be fixed ASAP.');
return;
}
if (data) {
Object.keys(data).forEach(k => {
Object.keys(data).forEach((k) => {
finalData[k] = data[k];
});
}
const args = [finalData, msg];
const args = [ finalData, msg ];
sLogger[levelName].apply(sLogger, args);
}

View File

@ -1,15 +1,16 @@
'use strict';
// eslint-disable-line strict
const assert = require('assert');
const LogLevel = require('./LogLevel.js');
const Utils = require('./Utils.js');
const { serializeUids, generateUid, objectCopy } = Utils;
const serializeUids = Utils.serializeUids;
const generateUid = Utils.generateUid;
const objectCopy = Utils.objectCopy;
function ensureUidValidity(uid) {
if (uid.indexOf(':') !== -1) {
throw new Error(`RequestLogger UID "${uid}" contains an illegal `
+ 'character: \':\'.');
throw new Error(`RequestLogger UID "${uid}" contains an illegal character: ':'.`);
}
return uid;
}
@ -21,6 +22,9 @@ class EndLogger {
}
augmentedLog(level, msg, data) {
assert.strictEqual(this.logger.elapsedTime, null, 'The logger\'s'
+ 'end() wrapper should not be called more than'
+ ' once.');
// We can alter current instance, as it won't be usable after this
// call.
this.fields = objectCopy(this.fields, data || {});
@ -138,6 +142,7 @@ class EndLogger {
* request.
*/
class RequestLogger {
/**
* Constructor of the WereLogs Request Logger.
* This function takes a logger instance, a logging level, and a last
@ -173,7 +178,7 @@ class RequestLogger {
* @returns {undefined}
*/
constructor(logger, logLevel, dumpThreshold, endLevel, uids) {
let uidList;
let uidList = undefined;
if (!LogLevel.shouldLog(dumpThreshold, logLevel)) {
throw new Error('Logging Dump level should be equal or'
@ -183,10 +188,10 @@ class RequestLogger {
if (uids !== undefined && Array.isArray(uids)) {
uidList = uids.map(uid => ensureUidValidity(uid));
uidList.push(generateUid());
} else if (uids !== undefined && typeof uids === 'string') {
uidList = [ensureUidValidity(uids)];
} else if (uids !== undefined && typeof(uids) === 'string') {
uidList = [ ensureUidValidity(uids) ];
}
this.uids = uidList || [generateUid()];
this.uids = uidList || [ generateUid() ];
this.entries = [];
this.fields = {};
@ -365,6 +370,8 @@ class RequestLogger {
if (msg === undefined && data === undefined) {
return this.endLogger;
}
assert.strictEqual(this.elapsedTime, null, 'The "end()" logging method '
+ 'should not be called more than once.');
return this.log(this.endLevel, msg, data, true);
}
@ -381,6 +388,8 @@ class RequestLogger {
* @returns {undefined}
*/
errorEnd(msg, data) {
assert.strictEqual(this.elapsedTime, null, 'The "end()" logging method '
+ 'should not be called more than once.');
return this.log('error', msg, data, true);
}
@ -421,45 +430,38 @@ class RequestLogger {
'Werelogs API was mis-used.'
+ ' This development error should be fixed ASAP.',
{
callparams: [msg, logFields],
},
);
'callparams': [ msg, logFields ],
});
return;
}
const fields = objectCopy({}, this.fields, logFields || {});
const endFlag = isEnd || false;
// removes object references
const _logFields = logFields ?
JSON.parse(JSON.stringify(logFields)) : {};
/*
* 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();
if (_logFields.time === undefined) {
_logFields.time = Date.now();
}
// eslint-disable-next-line camelcase
fields.req_id = serializeUids(this.uids);
_logFields.req_id = serializeUids(this.uids);
const endFlag = isEnd || false;
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
_logFields.elapsed_ms = this.elapsedTime[0] * 1000
+ this.elapsedTime[1] / 1000000;
}
// const fields = objectCopy({}, this.fields, _logFields || {});
const logEntry = {
level,
fields,
fields: _logFields,
msg,
};
this.entries.push(logEntry);
if (LogLevel.shouldLog(level, this.dumpThreshold)) {
this.entries.forEach(entry => {
this.entries.forEach((entry) => {
this.doLogIO(entry);
});
this.entries = [];
@ -484,24 +486,25 @@ class RequestLogger {
* @returns {undefined}
*/
doLogIO(logEntry) {
const fields = objectCopy({}, this.fields, logEntry.fields);
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}`);

View File

@ -1,17 +1,6 @@
// eslint-disable-line strict
'use strict';
const os = require('os');
const safeJSONStringify = require('safe-json-stringify');
const fastJSONStringify = require('fast-safe-stringify')
function errorStackReplacer(key, value) {
if (value instanceof Error) {
return value.stack;
}
return value;
}
/*
* This function safely stringifies JSON. If an exception occcurs (due to
* circular references, exceptions thrown from object getters etc.), the module
@ -23,13 +12,11 @@ function errorStackReplacer(key, value) {
function safeStringify(obj) {
let str;
try {
// Try to stringify the object (fast version)
str = fastJSONStringify(obj, errorStackReplacer);
str = JSON.stringify(obj);
} catch (e) {
// fallback to remove circular object references or other exceptions
// eslint-disable-next-line no-param-reassign
obj.unsafeJSON = true;
return safeJSONStringify(obj, errorStackReplacer);
return safeJSONStringify(obj);
}
return str;
}
@ -45,11 +32,11 @@ function isWriteableStream(s) {
class SimpleLogger {
constructor(name, streams) {
this.name = name;
this.streams = [{ level: 'trace', stream: process.stdout }];
this.streams = [ { level: 'info', stream: process.stdout } ];
if (streams) {
if (!Array.isArray(streams)) {
throw new Error('Invalid streams. streams must be an array'
+ ' list of writeable streams');
throw new Error('Invalid streams. streams must be an array list' +
' of writeable streams');
}
/*
* This is for backwards compatibility. current config in projects
@ -60,7 +47,6 @@ class SimpleLogger {
*/
this.streams = streams.filter(isWriteableStream);
}
this.hostname = os.hostname();
}
log(level, fields, message) {
@ -76,12 +62,11 @@ class SimpleLogger {
// TODO - Protect these fields from being overwritten
logFields.level = level;
logFields.message = logMsg;
logFields.hostname = this.hostname;
logFields.hostname = os.hostname();
logFields.pid = process.pid;
const safeString = safeStringify(logFields);
this.streams.forEach(s => s.stream
.write(`${safeString}\n`));
this.streams.forEach( s => s.stream
.write(safeStringify(logFields) + '\n'));
}
info(fields, message) {

View File

@ -1,38 +1,18 @@
// eslint-disable-line strict
/**
* @constant
* @type {String[]} - The lookup table to generate the UID
*/
const lut = [];
for (let i = 0; i < 256; i++) {
lut[i] = (i < 16 ? '0' : '') + (i).toString(16);
}
'use strict';
/**
* This function generates a string uid.
*
* The base algorithm is taken from here: http://jcward.com/UUID.js
* And is explained here: http://stackoverflow.com/a/21963136
*
* @returns {string} An hexadecimal string representation of an unique
* id made of 80 bits.of entropy.
*/
function generateUid() {
const d0 = Math.random() * 0xffffffff | 0;
const d1 = Math.random() * 0xffffffff | 0;
const d2 = Math.random() * 0xffffffff | 0;
return lut[d0 & 0xff]
+ lut[d0 >> 8 & 0xff]
+ lut[d0 >> 16 & 0xff]
+ lut[d1 & 0xff]
+ lut[d1 >> 8 & 0xff]
+ lut[d1 >> 16 & 0x0f | 0x40]
+ lut[d2 & 0x3f | 0x80]
+ lut[d2 >> 8 & 0xff]
+ lut[d2 >> 16 & 0xff]
+ lut[d2 >> 24 & 0xff];
function s4() {
return Math.floor((1 + Math.random()) * 0x10000)
.toString(16)
.substring(1);
}
return s4() + s4() + s4() + s4() + s4();
}
/**
@ -52,35 +32,29 @@ function serializeUids(uidList) {
* This function unserializes an array of UIDs from a string and returns the
* generated Array.
*
* @param {string} stringdata - The string data of the serialized array of UIDs
* @param {string} stringdata - The string data of the serialized array of UIDs
*
* @returns {string[]} - The unserialized array of string UIDs
* @returns {string[]} The unserialized array of string UIDs
*/
function unserializeUids(stringdata) {
return stringdata.split(':');
}
/**
* This function copies the properties from the source object to the target
* object.
*
* This function copies the properties from the source object to the target object
* @param {...object} target - object to be copied to
* @returns {object} - target object
*/
function objectCopy(target) {
const result = target;
/* eslint-disable prefer-rest-params */
const nb = arguments.length;
for (let i = 1; i < nb; i++) {
const source = arguments[i];
const keys = Object.keys(source);
const keysNb = keys.length;
for (let j = 0; j < keysNb; j++) {
const key = keys[j];
result[key] = source[key];
}
let source;
function copy(f) {
result[f] = source[f];
}
for (let i = 1; i < arguments.length; i++) {
source = arguments[i];
Object.keys(source).forEach(copy);
}
/* eslint-enable prefer-rest-params */
return result;
}

View File

@ -1,72 +0,0 @@
// eslint-disable-line strict
const Config = require('./Config.js');
const Logger = require('./Logger.js');
class API {
/**
* This is the constructor of the Logger class. It takes optional
* configuration parameters, that allow to modify its behavior.
*
* @param {object} config - A configuration object for werelogs.
* @param {string} config.level - The name of the logging level ('trace',
* 'debug', 'info', 'warn', 'error' and
* 'fatal' in order of importance.)
* @param {string} config.dump - The name of the log dumping level
* ('trace', 'debug', 'info', 'warn',
* 'error' and 'fatal' in order of
* importance.)
* @param {object[]} config.streams - The streams into which to log. This
* is an Array of objects which have a
* field named 'stream', which is
* writeable.
*/
constructor(config) {
this.config = new Config(config);
this.preboundLogger = Logger.bind(null, this.config);
}
/**
* This is a thunk function that allows reconfiguring the streams and log
* levels of all Logger and future RequestLogger objects. Note that
* existing RequestLogger will live their lifespan retaining the old
* configuration.
* If the provided configuration is erroneous, the function may throw
* exceptions depending on the detected configuration error. Please see the
* Config class's documentation about that.
*
* @throws {TypeError} - One of the provided arguments is not of the
* expected type
* @throws {RangeError} - The logging level provided is not part of the
* supported logging levels
* @throws {Error} - A human-readable message providing details about
* a logic error due to the input parameters
* provided.
*
* @param {object} config - A configuration object for werelogs.
* @param {string} config.level - The name of the logging level ('trace',
* 'debug', 'info', 'warn', 'error' and
* 'fatal' in order of importance.)
* @param {string} config.dump - The name of the log dumping level
* ('trace', 'debug', 'info', 'warn',
* 'error' and 'fatal' in order of
* importance.)
* @param {object[]} config.streams - The streams into which to log. This
* is an Array of objects which have a
* field named 'stream', which is
* writeable.
*
* @returns {undefined}
*
*/
reconfigure(config) {
this.config.update(config);
}
get Logger() {
return this.preboundLogger;
}
}
module.exports = API;

View File

@ -1,106 +0,0 @@
/**
* @returns {string} a timestamp in ISO format YYYY-MM-DDThh:mm:ss.sssZ
*/
const defaultTimestamp = () => new Date().toISOString();
/**
* Prints on stderr a timestamp, the origin and the error
*
* If no other instructions are needed on uncaughtException,
* consider using `catchAndTimestampStderr` directly.
*
* @example
* process.on('uncaughtException', (err, origin) => {
* printErrorWithTimestamp(err, origin);
* // server.close();
* // file.close();
* process.nextTick(() => process.exit(1));
* });
* // Don't forget to timestamp warning
* catchAndTimestampWarning();
* @param {Error} err see process event uncaughtException
* @param {uncaughtException|unhandledRejection} origin see process event
* @param {string} [date=`defaultTimestamp()`] Date to print
* @returns {boolean} see process.stderr.write
*/
function printErrorWithTimestamp(
err, origin, date = defaultTimestamp(),
) {
return process.stderr.write(`${date}: ${origin}:\n${err.stack}\n`);
}
/**
* Prefer using `catchAndTimestampStderr` instead of this function.
*
* Adds listener for uncaughtException to print with timestamp.
*
* If you want to manage the end of the process, you can set exitCode to null.
* Or use `printErrorWithTimestamp` in your own uncaughtException listener.
*
* @param {Function} [dateFct=`defaultTimestamp`] Fct returning a formatted date
* @param {*} [exitCode=1] On uncaughtException, if not null, `process.exit`
* will be called with this value
* @returns {undefined}
*/
function catchAndTimestampUncaughtException(
dateFct = defaultTimestamp, exitCode = 1,
) {
process.on('uncaughtException', (err, origin) => {
printErrorWithTimestamp(err, origin, dateFct());
if (exitCode !== null) {
process.nextTick(() => process.exit(exitCode));
}
});
}
/**
* Forces the use of `--trace-warnings` and adds a date in warning.detail
* The warning will be printed by the default `onWarning`
*
* @param {string} [dateFct=`defaultTimestamp`] Fct returning a formatted date
* @returns {undefined}
*/
function catchAndTimestampWarning(dateFct = defaultTimestamp) {
process.traceProcessWarnings = true;
// must be executed first, before the default `onWarning`
process.prependListener('warning', warning => {
if (warning.detail) {
// eslint-disable-next-line no-param-reassign
warning.detail += `\nAbove Warning Date: ${dateFct()}`;
} else {
// eslint-disable-next-line no-param-reassign
warning.detail = `Above Warning Date: ${dateFct()}`;
}
});
}
/**
* Adds listener for uncaughtException and warning to print them with timestamp.
*
* If you want to manage the end of the process, you can set exitCode to null.
* Or use `printErrorWithTimestamp` in your own uncaughtException listener.
*
* @example
* const { stderrUtils } = require('werelogs');
* // first instruction in your index.js or entrypoint
* stderrUtils.catchAndTimestampStderr();
*
* @param {Function} [dateFct=`defaultTimestamp`] Fct returning a formatted date
* @param {*} [exitCode=1] On uncaughtException, if not null, `process.exit`
* will be called with this value
* @returns {undefined}
*/
function catchAndTimestampStderr(
dateFct = defaultTimestamp, exitCode = 1,
) {
catchAndTimestampUncaughtException(dateFct, exitCode);
catchAndTimestampWarning(dateFct);
}
module.exports = {
defaultTimestamp,
printErrorWithTimestamp,
catchAndTimestampUncaughtException,
catchAndTimestampWarning,
catchAndTimestampStderr,
};

View File

@ -1,18 +1,15 @@
{
"name": "werelogs",
"engines": {
"node": ">=10"
},
"version": "8.1.5",
"version": "1.1.0",
"description": "An efficient raw JSON logging library aimed at micro-services architectures.",
"main": "index.js",
"scripts": {
"gendoc": "jsdoc $(git ls-files 'lib/*.js') -d doc",
"lint": "eslint $(git ls-files '*.js')",
"lint_md": "markdownlint $(git ls-files '*.md')",
"lint_md": "mdlint $(git ls-files '*.md')",
"test": "mocha tests/unit/",
"ft_test": "(npm pack && cp werelogs-*.tgz tests/functional && cd tests/functional && cp -R ../../node_modules/ node_modules/ && npm install werelogs-*.tgz && ./node_modules/.bin/mocha . multi-modules/ && rm -rf tests/functional/node_modules tests/functional/werelogs-*.tgz tests/functional/*lock*)",
"coverage": "nyc ./node_modules/.bin/_mocha tests/unit"
"ft_test": "rm -rf tests/functional/node_modules && npm pack && cp -R node_modules werelogs-*.tgz tests/functional && cd tests/functional && npm install werelogs-*.tgz && ./node_modules/.bin/mocha . multi-modules/ && cd -",
"coverage": "istanbul cover ./node_modules/.bin/_mocha tests/unit"
},
"repository": {
"type": "git",
@ -33,20 +30,16 @@
},
"homepage": "https://github.com/scality/werelogs#readme",
"dependencies": {
"fast-safe-stringify": "^2.1.1",
"safe-json-stringify": "^1.2.0"
"safe-json-stringify": "^1.0.3"
},
"devDependencies": {
"eslint": "^7.32.0",
"eslint-config-airbnb": "^18.2.1",
"eslint-config-scality": "git+https://git.yourcmc.ru/vitalif/zenko-eslint-config-scality.git",
"eslint-plugin-import": "^2.22.1",
"eslint-plugin-jsx-a11y": "^6.4.1",
"eslint-plugin-react": "^7.26.0",
"eslint-plugin-react-hooks": "^4.2.0",
"jsdoc": "^3.4.3",
"markdownlint-cli": "^0.27.1",
"mocha": ">=3.1.2",
"nyc": "^15.1.0"
"eslint": "^1.10.1",
"eslint-config-airbnb": "^1.0.2",
"eslint-plugin-react": "^3.10.0",
"istanbul": "^1.0.0-alpha",
"istanbul-api": "==1.0.0-alpha.9",
"jsdoc": "^3.4.0",
"mdlint": "^0.1.0",
"mocha": "^2.3.4"
}
}

View File

@ -1,20 +1,20 @@
// eslint-disable-line strict
'use strict';
const assert = require('assert');
const LogLevel = require('../lib/LogLevel.js');
class DummyLogger {
constructor() {
this.ops = [];
this.counts = {
trace: 0,
debug: 0,
info: 0,
warn: 0,
error: 0,
fatal: 0,
'trace': 0,
'debug': 0,
'info': 0,
'warn': 0,
'error': 0,
'fatal': 0,
};
}
@ -43,7 +43,7 @@ class DummyLogger {
}
_doLog(level, obj, msg) {
this.ops.push([level, [obj, msg]]);
this.ops.push([ level, [ obj, msg]]);
this.counts[level] += 1;
}
}
@ -57,8 +57,7 @@ function computeBehavior(filterLevel, logLevel, testLevel) {
return {
value,
msg: `Expected ${logLevel} to be called ${value} times with `
+ `filter level ${filterLevel}.`,
'msg': `Expected ${logLevel} to be called ${value} times with filter level ${filterLevel}.`,
};
}
@ -69,14 +68,12 @@ function genericFilterGenerator(filterLevel, testLevel, createLogger) {
const logger = createLogger(dummyLogger, filterLevel);
switch (testLevel) {
/* eslint-disable no-multi-spaces */
case 'trace': logger.trace('test trace'); break;
case 'debug': logger.debug('test debug'); break;
case 'info': logger.info('test info'); break;
case 'warn': logger.warn('test warn'); break;
case 'error': logger.error('test error'); break;
case 'fatal': logger.fatal('test fatal'); break;
/* eslint-enable no-multi-spaces */
default:
done(new Error('Unexpected testLevel name: ', testLevel));
}
@ -107,10 +104,9 @@ function loggingMisuseGenerator(test, createLogger) {
logger.info.apply(logger, test.args);
},
Error,
`Werelogs should not throw with ${test.desc}`,
);
'Werelogs should not throw with ' + test.desc);
assert(dummyLogger.ops[0][0], 'fatal',
'Expected the Module Logger to have logged a fatal message.');
'Expected the Module Logger to have logged a fatal message.');
done();
};
}

View File

@ -1,12 +1,10 @@
// eslint-disable-line strict
'use strict';
const assert = require('assert');
const { PassThrough } = require('stream');
const PassThrough = require('stream').PassThrough;
const pass = new PassThrough;
const pass = new PassThrough();
const werelogs = require('werelogs'); // eslint-disable-line
const Logger = require('werelogs');
// With PassThrough, SimpleLogger can use it as Writeable stream and all the
// data being written can be read into a variable
@ -17,23 +15,22 @@ pass.on('data', data => {
logBuffer.records.push(data.toString());
});
werelogs.configure({
level: 'info',
dump: 'error',
streams: [{
stream: pass,
type: 'raw',
}],
});
function createModuleLogger() {
return new werelogs.Logger('FT-test');
return new Logger('FT-test', {
level: 'info',
dump: 'error',
streams: [ {
stream: pass,
type: 'raw',
} ],
});
}
function checkFields(fields) {
const record = JSON.parse(logBuffer.records[0].trim());
Object.keys(fields).forEach(k => {
if (Object.prototype.hasOwnProperty.call(fields, k)) {
Object.keys(fields).forEach((k) => {
if (fields.hasOwnProperty(k)) {
assert.deepStrictEqual(record[k], fields[k]);
}
});
@ -48,16 +45,16 @@ describe('Werelogs is usable as a dependency', () => {
afterEach(() => {
logBuffer.records = [];
});
it('Should be able to create a logger', done => {
it('Should be able to create a logger', (done) => {
assert.doesNotThrow(
createModuleLogger,
Error,
'Werelogs threw an exception trying to create a ModuleLogger.',
'Werelogs threw an exception trying to create a ModuleLogger.'
);
done();
});
it('Should be able to log a simple message', done => {
it('Should be able to log a simple message', (done) => {
const logger = createModuleLogger();
const msg = 'This is a simple message';
logger.info(msg);
@ -65,14 +62,10 @@ describe('Werelogs is usable as a dependency', () => {
done();
});
it('Should be able to log a message and additional fields', done => {
it('Should be able to log a message and additional fields', (done) => {
const logger = createModuleLogger();
const msg = 'This is a message with added fields';
const fields = {
errorCode: 9,
description: 'TestError',
options: { dump: false },
};
const fields = { errorCode: 9, description: 'TestError', options: { dump: false } };
logger.info(msg, fields);
assert.strictEqual(parseLogEntry().message, msg);
checkFields(fields);
@ -84,16 +77,18 @@ describe('Werelogs is usable as a dependency', () => {
afterEach(() => {
logBuffer.records = [];
});
it('Should be able to create a logger', done => {
it('Should be able to create a logger', (done) => {
assert.doesNotThrow(
() => createModuleLogger().newRequestLogger(),
() => {
return createModuleLogger().newRequestLogger();
},
Error,
'Werelogs threw an exception trying to create a ModuleLogger.',
'Werelogs threw an exception trying to create a ModuleLogger.'
);
done();
});
it('Should be able to log a simple message', done => {
it('Should be able to log a simple message', (done) => {
const logger = createModuleLogger().newRequestLogger();
const msg = 'This is a simple message';
logger.info(msg);
@ -101,14 +96,10 @@ describe('Werelogs is usable as a dependency', () => {
done();
});
it('Should be able to log a message and additional fields', done => {
it('Should be able to log a message and additional fields', (done) => {
const logger = createModuleLogger().newRequestLogger();
const msg = 'This is a message with added fields';
const fields = {
errorCode: 9,
description: 'TestError',
options: { dump: false },
};
const fields = { errorCode: 9, description: 'TestError', options: { dump: false } };
logger.info(msg, fields);
assert.strictEqual(parseLogEntry().message, msg);
checkFields(fields);

View File

@ -1,14 +1,13 @@
const assert = require('assert');
const { PassThrough } = require('stream');
const PassThrough = require('stream').PassThrough;
const Werelogs = require('werelogs'); // eslint-disable-line
const Werelogs = require('werelogs');
const modules = [
require('./module1.js'),
require('./module2.js'),
require('./module3.js'),
];
const pass = new PassThrough();
const pass = new PassThrough;
const logBuffer = {
records: [],
@ -17,10 +16,9 @@ pass.on('data', data => {
logBuffer.records.push(JSON.parse(data.toString().trim()));
});
describe('Config is shared and unique within one API', () => {
it('should find all log entries in the RingBuffer with the right '
+ 'module name', done => {
Werelogs.configure({
describe('Config is shared and unique within one program', () => {
it('should find all log entries in the RingBuffer with the right module name', (done) => {
const log = new Werelogs('test-index', {
level: 'debug',
dump: 'fatal',
streams: [{
@ -28,12 +26,10 @@ describe('Config is shared and unique within one API', () => {
stream: pass,
}],
});
const log = new Werelogs.Logger('test-index');
modules.forEach(mod => { mod(); });
modules.forEach((mod) => { mod(); });
log.warn('Logging as warn');
const rLog = log.newRequestLogger();
rLog.info('Logging request as info');
/* eslint-disable max-len */
assert.deepStrictEqual(logBuffer.records.length, 5, 'Expected to see 5 log entries in the ring buffer.');
assert.deepStrictEqual(logBuffer.records[0].message, 'Logging as info');
assert.deepStrictEqual(logBuffer.records[0].name, 'test-mod1');
@ -51,7 +47,6 @@ describe('Config is shared and unique within one API', () => {
assert.deepStrictEqual(logBuffer.records[4].name, 'test-index');
assert.deepStrictEqual(logBuffer.records[4].level, 'info');
assert.notStrictEqual(logBuffer.records[4].req_id, undefined);
/* eslint-enable max-len */
done();
});
});

View File

@ -1,4 +1,4 @@
const Werelogs = require('werelogs').Logger; // eslint-disable-line
const Werelogs = require('werelogs');
const log = new Werelogs('test-mod1');

View File

@ -1,4 +1,4 @@
const Werelogs = require('werelogs').Logger; // eslint-disable-line
const Werelogs = require('werelogs');
const log = new Werelogs('test-mod2');

View File

@ -1,4 +1,4 @@
const Werelogs = require('werelogs').Logger; // eslint-disable-line
const Werelogs = require('werelogs');
const log = new Werelogs('test-mod3');

View File

@ -1,58 +1,53 @@
/* eslint-disable max-len */
const assert = require('assert');
const Config = require('../../lib/Config.js');
describe('Config', () => {
const config = new Config();
beforeEach(() => {
config.reset();
Config.reset();
});
it('should work with default configuration', done => {
it('should work with default configuration', (done) => {
assert.doesNotThrow(
() => {
config.logger.info('test message');
Config.logger.info('test message');
},
Error,
);
Error);
done();
});
it('log level should be updateable', done => {
config.update({ level: 'debug' });
assert.strictEqual(config.level, 'debug', 'Expected config\'s log level to be updated.');
it('log level should be updateable', (done) => {
Config.update({ level: 'debug' });
assert.strictEqual(Config.level, 'debug', 'Expected Config\'s log level to be updated.');
done();
});
it('dump threshold should be updateable', done => {
const origDump = config.dump;
assert.notStrictEqual(origDump, 'warn', 'Expected original config.dump to differ from value to update.');
config.update({ dump: 'warn' });
assert.strictEqual(config.dump, 'warn', 'Expected config\'s dump threshold to be updated.');
it('dump threshold should be updateable', (done) => {
const origDump = Config.dump;
assert.notStrictEqual(origDump, 'warn', 'Expected original Config.dump to differ from value to update.');
Config.update({ dump: 'warn' });
assert.strictEqual(Config.dump, 'warn', 'Expected Config\'s dump threshold to be updated.');
done();
});
it('end logging level should be updateable', done => {
const origEnd = config.end;
assert.notStrictEqual(origEnd, 'trace', 'Expected original config.end to differ from value to update.');
config.update({ end: 'trace' });
assert.strictEqual(config.end, 'trace', 'Expected config\'s end log level to be updated.');
it('end logging level should be updateable', (done) => {
const origEnd = Config.end;
assert.notStrictEqual(origEnd, 'trace', 'Expected original Config.end to differ from value to update.');
Config.update({ end: 'trace' });
assert.strictEqual(Config.end, 'trace', 'Expected Config\'s end log level to be updated.');
done();
});
it('should not be modified by an empty config object', done => {
const origLevel = config.level;
const origDump = config.dump;
const origLogger = config.logger;
const origStreams = config.streams;
config.update({});
assert.deepStrictEqual(origLevel, config.level, 'Expected logging level not to have changed.');
assert.deepStrictEqual(origDump, config.dump, 'Expected dump threshold not to have changed.');
assert.strictEqual(origLogger, config.logger, 'Expected logger not to have changed.');
assert.deepStrictEqual(origStreams, config.streams, 'Expected streams not to have changed.');
it('should not be modified by an empty config object', (done) => {
const origLevel = Config.level;
const origDump = Config.dump;
const origLogger = Config.logger;
const origStreams = Config.streams;
Config.update({});
assert.deepStrictEqual(origLevel, Config.level, 'Expected logging level not to have changed.');
assert.deepStrictEqual(origDump, Config.dump, 'Expected dump threshold not to have changed.');
assert.strictEqual(origLogger, Config.logger, 'Expected logger not to have changed.');
assert.deepStrictEqual(origStreams, Config.streams, 'Expected streams not to have changed.');
done();
});
});

View File

@ -1,5 +1,4 @@
// eslint-disable-line strict
'use strict';
const assert = require('assert');
@ -13,97 +12,89 @@ function generateValidThrowTest(level) {
},
Error,
'Expected level to be valid and '
+ 'the function not to throw an Error.',
);
+ 'the function not to throw an Error.');
done();
};
}
describe('LogLevel', () => {
describe('throwIfInvalid(level)', () => {
it('should throw on invalid string', done => {
it('should throw on invalid string', (done) => {
assert.throws(
() => {
LogLevel.throwIfInvalid('invalid');
},
RangeError,
'Expected function to throw an Error instance due to '
+ 'invalid log level.',
);
+ 'invalid log level.');
done();
});
it('should not throw on "trace" level',
generateValidThrowTest('trace'));
generateValidThrowTest('trace'));
it('should not throw on "debug" level',
generateValidThrowTest('debug'));
generateValidThrowTest('debug'));
it('should not throw on "info" level',
generateValidThrowTest('info'));
generateValidThrowTest('info'));
it('should not throw on "warn" level',
generateValidThrowTest('warn'));
generateValidThrowTest('warn'));
it('should not throw on "error" level',
generateValidThrowTest('error'));
generateValidThrowTest('error'));
it('should not throw on "fatal" level',
generateValidThrowTest('fatal'));
generateValidThrowTest('fatal'));
});
describe('shouldLog(level, floor)', () => {
it('should return true on "trace" parameters', done => {
it('should return true on "trace" parameters', (done) => {
assert.strictEqual(
LogLevel.shouldLog('trace', 'trace'),
true,
'Expected trace floor to allow logging trace level.',
);
'Expected trace floor to allow logging trace level.');
done();
});
it('should return true on "debug" parameters', done => {
it('should return true on "debug" parameters', (done) => {
assert.strictEqual(
LogLevel.shouldLog('debug', 'debug'),
true,
'Expected debug floor to allow logging debug level.',
);
'Expected debug floor to allow logging debug level.');
done();
});
it('should return true on "info" parameters', done => {
it('should return true on "info" parameters', (done) => {
assert.strictEqual(
LogLevel.shouldLog('info', 'info'),
true,
'Expected info floor to allow logging info level.',
);
'Expected info floor to allow logging info level.');
done();
});
it('should return true on "warn" parameters', done => {
it('should return true on "warn" parameters', (done) => {
assert.strictEqual(
LogLevel.shouldLog('warn', 'warn'),
true,
'Expected warn floor to allow logging warn level.',
);
'Expected warn floor to allow logging warn level.');
done();
});
it('should return true on "error" parameters', done => {
it('should return true on "error" parameters', (done) => {
assert.strictEqual(
LogLevel.shouldLog('error', 'error'),
true,
'Expected error floor to allow logging error level.',
);
'Expected error floor to allow logging error level.');
done();
});
it('should return true on "fatal" parameters', done => {
it('should return true on "fatal" parameters', (done) => {
assert.strictEqual(
LogLevel.shouldLog('fatal', 'fatal'),
true,
'Expected fatal floor to allow logging fatal level.',
);
'Expected fatal floor to allow logging fatal level.');
done();
});
});

View File

@ -1,15 +1,15 @@
// eslint-disable-line strict
'use strict';
const assert = require('assert');
const { genericFilterGenerator, loggingMisuseGenerator, DummyLogger } = require('../Utils');
const Utils = require('../Utils.js');
const genericFilterGenerator = Utils.genericFilterGenerator;
const loggingMisuseGenerator = Utils.loggingMisuseGenerator;
const DummyLogger = Utils.DummyLogger;
const Config = require('../../lib/Config.js');
const RequestLogger = require('../../lib/RequestLogger.js');
const Logger = require('../../lib/Logger.js');
const config = new Config();
const Logger = require('../../index.js');
/*
* This function is a thunk-function calling the Utils' filterGenerator with
@ -18,107 +18,163 @@ const config = new Config();
*/
function filterGenerator(logLevel, callLevel) {
function createModuleLogger(dummyLogger, filterLevel) {
const logger = new Logger('TestModuleLogger',
{
level: filterLevel,
dump: 'fatal',
});
/*
* Here, patch the config by setting a specifically designed dummyLogger
* Here, patch the Config by setting a specificly designed dummyLogger
* for testing purposes that will help us collect runtime data.
*/
const testConfig = new Config({ level: filterLevel, dump: 'fatal' });
testConfig.simpleLogger = dummyLogger;
Config.simpleLogger = dummyLogger;
return new Logger(testConfig, 'TestModuleLogger');
return logger;
}
return genericFilterGenerator(logLevel, callLevel, createModuleLogger);
}
function checkFields(src, result) {
Object.keys(src).forEach(k => {
if (Object.prototype.hasOwnProperty.call(src, k)) {
Object.keys(src).forEach((k) => {
if (src.hasOwnProperty(k)) {
assert.deepStrictEqual(result[k], src[k]);
}
});
assert.ok(Object.prototype.hasOwnProperty.call(result, 'time'));
// Time field should be current give or take 1s
assert.ok((Date.now() - result.time) < 1000);
}
describe('Logger is usable:', () => {
describe('WereLogs Logger is usable:', () => {
beforeEach(() => {
config.reset();
Config.reset();
});
it('Cannot be instanciated without parameters', done => {
assert.throws(
() => new Logger(),
TypeError,
'Logger Instanciation should not succeed without parameter.',
);
it('Can be instanciated with only a name', (done) => {
assert.doesNotThrow(
() => {
return new Logger('WereLogsTest');
},
Error,
'WereLogs Instanciation should not throw any kind of error.');
done();
});
it('Cannot be instanciated with only a config', done => {
it('Cannot be instanciated with invalid log level', (done) => {
assert.throws(
() => new Logger(config),
TypeError,
'Logger Instanciation should not be succeed without a name.',
);
() => {
return new Logger('test', {level: 'invalidlevel'});
},
RangeError,
'WereLogs should not be instanciable without the proper logging levels.');
done();
});
it('Cannot be instanciated with a bad config type', done => {
it('Cannot be instanciated with invalid dump threshold level', (done) => {
assert.throws(
() => new Logger({ level: 'info' }, 'WereLogsTest'),
TypeError,
'Logger Instanciation should not succeed with a bad config type.',
);
() => {
return new Logger('test', {level: 'trace', dump: 'invalidlevel'});
},
RangeError,
'WereLogs should not be instanciable without the proper dumping threshold levels.');
done();
});
it('Cannot be instanciated with only a name', done => {
it('Cannot be instanciated with a non-Array in config.streams', (done) => {
assert.throws(
() => new Logger('WereLogsTest'),
TypeError,
'Logger Instanciation should not succeed with only a name.',
);
() => {
return new Logger('test', {streams: process.stdout});
},
Error,
'Werelogs should not be instanciable with a stream option that is not an array.');
done();
});
it('Can create Per-Request Loggers', done => {
const logger = new Logger(config, 'test');
it('Cannot be instanciated with an empty Array in config.streams', (done) => {
assert.throws(
() => {
return new Logger('test', {streams: []});
},
Error,
'Werelogs should not be instanciable with an empty array for the streams option.');
done();
});
it('Cannot set logging level to invalid level at runtime', (done) => {
const logger = new Logger('test');
assert.throws(
() => {
logger.setLevel('invalidLevel');
},
RangeError,
'WereLogs should not be able to set log level to an invalid level.');
done();
});
it('Can set logging level at runtime', (done) => {
const logger = new Logger('test');
assert.doesNotThrow(
() => {
logger.setLevel('fatal');
},
RangeError,
'WereLogs should be able to set log level at runtime.');
done();
});
it('Cannot set dump threshold to invalid level at runtime', (done) => {
const logger = new Logger('test');
assert.throws(
() => {
logger.setDumpThreshold('invalidLevel');
},
RangeError,
'WereLogs should not be able to set dump threshold to an invalid level.');
done();
});
it('Can set dump threshold at runtime', (done) => {
const logger = new Logger('test');
assert.doesNotThrow(
() => {
logger.setDumpThreshold('fatal');
},
RangeError,
'WereLogs should be able to set dump threshold at runtime.');
done();
});
it('Can create Per-Request Loggers', (done) => {
const logger = new Logger('test');
assert.doesNotThrow(
() => {
logger.newRequestLogger();
},
Error,
'Werelogs should not throw when creating a request logger.',
);
done();
});
it('Can create Per-Request Loggers from a Serialized UID Array', done => {
const logger = new Logger(config, 'test');
assert.doesNotThrow(
() => {
logger.newRequestLogger();
},
Error,
// eslint-disable-next-line max-len
'Werelogs should not throw when creating a request logger from a Serialized UID Array.',
);
const reqLogger = logger.newRequestLoggerFromSerializedUids(
'OneUID:SecondUID:TestUID:YouWinUID',
);
'Werelogs should not throw when creating a request logger.');
const reqLogger = logger.newRequestLogger();
assert(reqLogger instanceof RequestLogger, 'RequestLogger');
assert.deepStrictEqual(reqLogger.getUids().slice(0, -1),
['OneUID', 'SecondUID', 'TestUID', 'YouWinUID']);
done();
});
it('Uses the additional fields as expected', done => {
it('Can create Per-Request Loggers from a Serialized UID Array', (done) => {
const logger = new Logger('test');
assert.doesNotThrow(
() => {
logger.newRequestLogger();
},
Error,
'Werelogs should not throw when creating a request logger from a Serialized UID Array.');
const reqLogger = logger.newRequestLoggerFromSerializedUids('OneUID:SecondUID:TestUID:YouWinUID');
assert(reqLogger instanceof RequestLogger, 'RequestLogger');
assert.deepStrictEqual(reqLogger.getUids().slice(0, -1), ['OneUID', 'SecondUID', 'TestUID', 'YouWinUID']);
done();
});
it('Uses the additional fields as expected', (done) => {
const dummyLogger = new DummyLogger();
config.simpleLogger = dummyLogger;
const logger = new Logger(config, 'test');
const logger = new Logger('test');
Config.simpleLogger = dummyLogger;
const fields = {
ip: '127.0.0.1',
method: 'GET',
@ -130,31 +186,28 @@ describe('Logger is usable:', () => {
done();
});
/* eslint-disable max-len */
describe('Does not crash and logs a fatal message when mis-using its logging API', () => {
const testValues = [
{ desc: 'a string as second argument', args: ['test', 'second-param-string'] },
{ desc: 'a function as second argument', args: ['test', () => { }] }, // eslint-disable-line arrow-body-style
{ desc: 'a Number as second argument', args: ['test', 1] },
{ desc: 'more than 2 arguments', args: ['test', 2, 3, 4] },
{ desc: 'a string as second argument', args: [ 'test', 'second-param-string' ] },
{ desc: 'a function as second argument', args: [ 'test', () => { return; } ] },
{ desc: 'a Number as second argument', args: [ 'test', 1 ] },
{ desc: 'more than 2 arguments', args: [ 'test', 2, 3, 4 ] },
];
/* eslint-enable max-len */
function createMisusableLogger(dummyLogger) {
config.simpleLogger = dummyLogger;
const logger = new Logger(config, 'test');
const logger = new Logger('test');
Config.simpleLogger = dummyLogger;
return logger;
}
for (let i = 0; i < testValues.length; ++i) {
const test = testValues[i];
it(`Does not crash with ${test.desc}`,
loggingMisuseGenerator(test, createMisusableLogger));
it('Does not crash with ' + test.desc,
loggingMisuseGenerator(test, createMisusableLogger));
}
});
});
/* eslint-disable no-multi-spaces, max-len */
describe('Logger can log as specified by the log level', () => {
describe('Werelogs Module-level Logger can log as specified by the log level', () => {
it('Trace level does not filter trace level out', filterGenerator('trace', 'trace'));
it('Trace level does not filter debug level out', filterGenerator('trace', 'debug'));
it('Trace level does not filter info level out', filterGenerator('trace', 'info'));
@ -197,4 +250,3 @@ describe('Logger can log as specified by the log level', () => {
it('Fatal level filters error level out', filterGenerator('fatal', 'error'));
it('Fatal level does not filter fatal level out', filterGenerator('fatal', 'fatal'));
});
/* eslint-enable no-multi-spaces, max-len */

View File

@ -1,9 +1,11 @@
// eslint-disable-line strict
'use strict';
const assert = require('assert');
const { DummyLogger, genericFilterGenerator, loggingMisuseGenerator } = require('../Utils.js');
const Utils = require('../Utils.js');
const DummyLogger = Utils.DummyLogger;
const genericFilterGenerator = Utils.genericFilterGenerator;
const loggingMisuseGenerator = Utils.loggingMisuseGenerator;
const RequestLogger = require('../../lib/RequestLogger.js');
@ -21,21 +23,18 @@ function filterGenerator(logLevel, callLevel) {
}
function runLoggingDumpTest(commandHistory, expectedHistory, expectedCounts,
done) {
function runLoggingDumpTest(commandHistory, expectedHistory, expectedCounts, done) {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'trace', 'error', 'info');
commandHistory.every((val, index) => {
commandHistory.every(function doLogWithLevel(val, index) {
switch (val) {
/* eslint-disable no-multi-spaces */
case 'trace': reqLogger.trace(index); break;
case 'debug': reqLogger.debug(index); break;
case 'info': reqLogger.info(index); break;
case 'warn': reqLogger.warn(index); break;
case 'error': reqLogger.error(index); break;
case 'fatal': reqLogger.fatal(index); break;
/* eslint-enable no-multi-spaces */
default:
done(new Error('Unexpected logging level name: ', val));
}
@ -43,40 +42,40 @@ function runLoggingDumpTest(commandHistory, expectedHistory, expectedCounts,
});
expectedHistory.every((val, index) => {
assert.strictEqual(dummyLogger.ops[index][0], val[0],
'Expected log entry levels to match.');
assert.strictEqual(dummyLogger.ops[index][1][1], val[1],
'Expected log entry values to match.');
assert.strictEqual(dummyLogger.ops[index][0], val[0], 'Expected log entry levels to match.');
assert.strictEqual(dummyLogger.ops[index][1][1], val[1], 'Expected log entry values to match.');
return true;
});
assert.deepEqual(dummyLogger.counts, expectedCounts);
}
/* eslint-disable no-multi-spaces, max-len */
describe('RequestLogger', () => {
describe('Object Instanciation', () => {
describe('Logging Levels Initialization', () => {
it('Throws if LogLevel is higher than dumpThreshold', done => {
it('Throws if LogLevel is higher than dumpThreshold', (done) => {
assert.throws(
() => new RequestLogger(undefined, 'fatal', 'debug', 'info'),
() => {
return new RequestLogger(undefined, 'fatal', 'debug', 'info');
},
Error,
'Dump level "debug" should not be valid with logging level "fatal".',
);
'Dump level "debug" should not be valid with logging level "fatal".');
done();
});
it('Works with LogLevel lesser or equal to DumpLevel', done => {
it('Works with LogLevel lesser or equal to DumpLevel', (done) => {
assert.doesNotThrow(
() => new RequestLogger(undefined, 'debug', 'fatal', 'info'),
() => {
return new RequestLogger(undefined, 'debug', 'fatal', 'info');
},
Error,
'Dump level "fatal" should be valid with logging level "debug".',
);
'Dump level "fatal" should be valid with logging level "debug".');
done();
});
});
describe('UID Initialization', () => {
it('defines an UID when none provided', done => {
it('defines an UID when none provided', (done) => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'debug', 'fatal', 'info');
assert.strictEqual(Array.isArray(reqLogger.uids), true, 'Expected uid list to be an Array.');
@ -84,7 +83,7 @@ describe('RequestLogger', () => {
done();
});
it('creates an UID array out of the provided UID string', done => {
it('creates an UID array out of the provided UID string', (done) => {
const dummyLogger = new DummyLogger();
const uids = 'BasicUid';
const reqLogger = new RequestLogger(dummyLogger, 'debug', 'fatal', 'info', uids);
@ -94,16 +93,17 @@ describe('RequestLogger', () => {
done();
});
it('throws when UID string provided contains a colon', done => {
it('throws when UID string provided contains a colon', (done) => {
assert.throws(
() => new RequestLogger(undefined, 'debug', 'fatal', 'info', 'pouet:tata'),
() => {
return new RequestLogger(undefined, 'debug', 'fatal', 'info', 'pouet:tata');
},
Error,
'UID string "pouet:tata" should be rejected by the RequestLogger constructor.',
);
'UID string "pouet:tata" should be rejected by the RequestLogger constructor.');
done();
});
it('expands the UID array when one is provided', done => {
it('expands the UID array when one is provided', (done) => {
const dummyLogger = new DummyLogger();
const uids = ['oneuid', 'twouid', 'threeuids'];
const reqLogger = new RequestLogger(dummyLogger, 'debug', 'fatal', 'info', uids);
@ -113,18 +113,19 @@ describe('RequestLogger', () => {
done();
});
it('throws when UID string Array provided contains an UID that contains a colon', done => {
it('throws when UID string Array provided contains an UID that contains a colon', (done) => {
assert.throws(
() => new RequestLogger(undefined, 'debug', 'fatal', 'info', ['OneUID', 'SecondUID', 'Test:DashUID']),
() => {
return new RequestLogger(undefined, 'debug', 'fatal', 'info', ['OneUID', 'SecondUID', 'Test:DashUID']);
},
Error,
'UID string "Test:DashUID" should be rejected by the RequestLogger constructor.',
);
'UID string "Test:DashUID" should be rejected by the RequestLogger constructor.');
done();
});
});
describe('getUids() method', () => {
it('retrieves a list of string UID', done => {
it('retrieves a list of string UID', (done) => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'info', 'error', 'info');
const uidlist = reqLogger.getUids();
@ -134,7 +135,7 @@ describe('RequestLogger', () => {
});
describe('Length of the UIDs array', () => {
it('default constructor yields a one-item UID list', done => {
it('default constructor yields a one-item UID list', (done) => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'info', 'error', 'info');
const uidlist = reqLogger.getUids();
@ -142,7 +143,7 @@ describe('RequestLogger', () => {
done();
});
it('manually-set UID constructor yields a one-item UID list', done => {
it('manually-set UID constructor yields a one-item UID list', (done) => {
const dummyLogger = new DummyLogger();
const myUid = 'ThisIsMyUid';
const reqLogger = new RequestLogger(dummyLogger, 'info', 'error', 'info', myUid);
@ -152,9 +153,9 @@ describe('RequestLogger', () => {
done();
});
it('manually-set parent UID List constructor yields a n+1 item UID list', done => {
it('manually-set parent UID List constructor yields a n+1 item UID list', (done) => {
const dummyLogger = new DummyLogger();
const myParentUidList = ['ThisIsMyOriginUid', 'ThisIsMySecondGenUid', 'ThisIsMyThirdGenUid'];
const myParentUidList = [ 'ThisIsMyOriginUid', 'ThisIsMySecondGenUid', 'ThisIsMyThirdGenUid' ];
const reqLogger = new RequestLogger(dummyLogger, 'info', 'error', 'info', myParentUidList);
const uidlist = reqLogger.getUids();
assert.strictEqual(uidlist.length, myParentUidList.length + 1, 'Expected n+1 item in UID Array compared to set UID List array');
@ -163,7 +164,7 @@ describe('RequestLogger', () => {
});
});
it('internal data cannot be set through returned UID List', done => {
it('internal data cannot be set through returned UID List', (done) => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'info', 'error', 'info');
const uidlist = reqLogger.getUids();
@ -174,11 +175,11 @@ describe('RequestLogger', () => {
});
describe('getSerializedUids()', () => {
it('Should return a properly serialized UID Array', done => {
it('Should return a properly serialized UID Array', (done) => {
const dummyLogger = new DummyLogger();
const uidList = ['FirstUID', 'SecondUID', 'ThirdUID', 'TestUID'];
const uidList = [ 'FirstUID', 'SecondUID', 'ThirdUID', 'TestUID' ];
const reqLogger = new RequestLogger(dummyLogger, 'info', 'error', 'info', uidList);
const expectedString = `FirstUID:SecondUID:ThirdUID:TestUID:${reqLogger.getUids()[4]}`;
const expectedString = 'FirstUID:SecondUID:ThirdUID:TestUID:' + reqLogger.getUids()[4];
assert.strictEqual(reqLogger.getSerializedUids(), expectedString, 'Expected serialized UID List to match expected data.');
done();
});
@ -187,10 +188,10 @@ describe('RequestLogger', () => {
describe('Does not crash when mis-using its logging API', () => {
const testValues = [
{ desc: 'a string as second argument', args: ['test', 'second-param-string'] },
{ desc: 'a function as second argument', args: ['test', function f() { }] },
{ desc: 'a Number as second argument', args: ['test', 1] },
{ desc: 'more than 2 arguments', args: ['test', 2, 3, 4] },
{ desc: 'a string as second argument', args: [ 'test', 'second-param-string' ] },
{ desc: 'a function as second argument', args: [ 'test', () => { return; } ] },
{ desc: 'a Number as second argument', args: [ 'test', 1 ] },
{ desc: 'more than 2 arguments', args: [ 'test', 2, 3, 4 ] },
];
function createMisusableRequestLogger(dummyLogger) {
return new RequestLogger(dummyLogger, 'info', 'error', 'info');
@ -198,8 +199,8 @@ describe('RequestLogger', () => {
for (let i = 0; i < testValues.length; ++i) {
const test = testValues[i];
it(`Does not crash with ${test.desc}`,
loggingMisuseGenerator(test, createMisusableRequestLogger));
it('Does not crash with ' + test.desc,
loggingMisuseGenerator(test, createMisusableRequestLogger));
}
});
@ -246,39 +247,33 @@ describe('RequestLogger', () => {
it('Fatal level filters error level out', filterGenerator('fatal', 'error'));
it('Fatal level does not filter fatal level out', filterGenerator('fatal', 'fatal'));
});
/* eslint-enable no-multi-spaces, max-len */
describe('Logging API regression testing', () => {
it('Should not alter the input fields when not actually logging',
done => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger,
'info', 'fatal', 'info');
const refFields = { hits: 45, count: 32 };
const usedFields = { ...refFields };
reqLogger.debug('test', usedFields);
assert.deepStrictEqual(usedFields, refFields);
done();
});
it('Should not alter the input fields when actually logging',
done => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger,
'info', 'fatal', 'info');
const refFields = { hits: 45, count: 32 };
const usedFields = { ...refFields };
reqLogger.info('test', usedFields);
assert.deepStrictEqual(usedFields, refFields);
done();
});
it('Should not alter the input fields when dumping', done => {
it('Should not alter the input fields when not actually logging', (done) => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger,
'info', 'fatal', 'info');
const refFields = { hits: 45, count: 32 };
const usedFields = { ...refFields };
const reqLogger = new RequestLogger(dummyLogger, 'info', 'fatal', 'info');
const refFields = { 'hits': 45, 'count': 32 };
const usedFields = Object.assign({}, refFields);
reqLogger.debug('test', usedFields);
assert.deepStrictEqual(usedFields, refFields);
done();
});
it('Should not alter the input fields when actually logging', (done) => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'info', 'fatal', 'info');
const refFields = { 'hits': 45, 'count': 32 };
const usedFields = Object.assign({}, refFields);
reqLogger.info('test', usedFields);
assert.deepStrictEqual(usedFields, refFields);
done();
});
it('Should not alter the input fields when dumping', (done) => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'info', 'fatal', 'info');
const refFields = { 'hits': 45, 'count': 32 };
const usedFields = Object.assign({}, refFields);
reqLogger.error('test', usedFields);
assert.deepStrictEqual(usedFields, refFields);
done();
@ -286,7 +281,7 @@ describe('RequestLogger', () => {
});
describe('Default Fields', () => {
it('should not modify the object passed as a parameter', done => {
it('should not modify the object passed as a parameter', (done) => {
const add1 = {
attr1: 0,
};
@ -294,8 +289,7 @@ describe('RequestLogger', () => {
attr2: 'string',
};
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger,
'info', 'fatal', 'info');
const reqLogger = new RequestLogger(dummyLogger, 'info', 'fatal', 'info');
reqLogger.addDefaultFields(add1);
reqLogger.addDefaultFields(add2);
assert.deepStrictEqual(add1, { attr1: 0 });
@ -303,192 +297,129 @@ describe('RequestLogger', () => {
done();
});
it('should add one added default field to the log entries', done => {
it('should add one added default field to the log entries', (done) => {
const clientInfo = {
clientIP: '127.0.0.1',
};
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger,
'info', 'fatal', 'info');
const reqLogger = new RequestLogger(dummyLogger, 'info', 'fatal', 'info');
reqLogger.addDefaultFields(clientInfo);
reqLogger.info('test message');
assert.strictEqual(clientInfo.clientIP,
dummyLogger.ops[0][1][0].clientIP);
assert.strictEqual(clientInfo.clientIP, dummyLogger.ops[0][1][0].clientIP);
done();
});
it('should add multiple added default fields to the log entries',
done => {
const clientInfo = {
clientIP: '127.0.0.1',
clientPort: '1337',
};
const requestInfo = {
object: '/tata/self.txt',
creator: 'Joddy',
};
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger,
'info', 'fatal', 'info');
reqLogger.addDefaultFields(clientInfo);
reqLogger.addDefaultFields(requestInfo);
reqLogger.info('test message');
assert.strictEqual(clientInfo.clientIP,
dummyLogger.ops[0][1][0].clientIP);
assert.strictEqual(clientInfo.clientPort,
dummyLogger.ops[0][1][0].clientPort);
assert.strictEqual(requestInfo.object,
dummyLogger.ops[0][1][0].object);
assert.strictEqual(requestInfo.creator,
dummyLogger.ops[0][1][0].creator);
done();
});
it('should add multiple added default fields to the log entries', (done) => {
const clientInfo = {
clientIP: '127.0.0.1',
clientPort: '1337',
};
const requestInfo = {
object: '/tata/self.txt',
creator: 'Joddy',
};
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'info', 'fatal', 'info');
reqLogger.addDefaultFields(clientInfo);
reqLogger.addDefaultFields(requestInfo);
reqLogger.info('test message');
assert.strictEqual(clientInfo.clientIP, dummyLogger.ops[0][1][0].clientIP);
assert.strictEqual(clientInfo.clientPort, dummyLogger.ops[0][1][0].clientPort);
assert.strictEqual(requestInfo.object, dummyLogger.ops[0][1][0].object);
assert.strictEqual(requestInfo.creator, dummyLogger.ops[0][1][0].creator);
done();
});
});
describe('Automatic Elapsed Time computation', () => {
describe('Deprecated API:', () => {
it('should include an "elapsed_ms" field in the last log entry',
done => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger,
'info', 'fatal', 'info');
reqLogger.end('Last message');
assert.strictEqual(dummyLogger.ops[0][1][1], 'Last message');
assert.notStrictEqual(dummyLogger.ops[0][1][0].elapsed_ms,
undefined);
assert.strictEqual(typeof dummyLogger.ops[0][1][0]
.elapsed_ms, 'number');
done();
});
it('should include an "elapsed_ms" field in the last log entry', (done) => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'info', 'fatal', 'info');
reqLogger.end('Last message');
assert.strictEqual(dummyLogger.ops[0][1][1], 'Last message');
assert.notStrictEqual(dummyLogger.ops[0][1][0].elapsed_ms, undefined);
assert.strictEqual(typeof(dummyLogger.ops[0][1][0].elapsed_ms), 'number');
done();
});
// eslint-disable-next-line max-len
it('should include an "elapsed_ms" field in the last log entry and be error level', () => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger,
'info', 'fatal', 'info');
const reqLogger = new RequestLogger(dummyLogger, 'info', 'fatal', 'info');
reqLogger.errorEnd('Last message failed');
assert.strictEqual(dummyLogger.ops[0][1][1],
'Last message failed');
assert.notStrictEqual(dummyLogger.ops[0][1][0].elapsed_ms,
undefined);
assert.strictEqual(typeof dummyLogger.ops[0][1][0].elapsed_ms,
'number');
assert.strictEqual(dummyLogger.ops[0][1][1], 'Last message failed');
assert.notStrictEqual(dummyLogger.ops[0][1][0].elapsed_ms, undefined);
assert.strictEqual(typeof(dummyLogger.ops[0][1][0].elapsed_ms), 'number');
assert.strictEqual(dummyLogger.ops[0][0], 'error');
});
});
const endLogging = {
trace: endLogger => endLogger.trace.bind(endLogger),
debug: endLogger => endLogger.debug.bind(endLogger),
info: endLogger => endLogger.info.bind(endLogger),
warn: endLogger => endLogger.warn.bind(endLogger),
error: endLogger => endLogger.error.bind(endLogger),
fatal: endLogger => endLogger.fatal.bind(endLogger),
trace: (endLogger) => { return endLogger.trace.bind(endLogger); },
debug: (endLogger) => { return endLogger.debug.bind(endLogger); },
info: (endLogger) => { return endLogger.info.bind(endLogger); },
warn: (endLogger) => { return endLogger.warn.bind(endLogger); },
error: (endLogger) => { return endLogger.error.bind(endLogger); },
fatal: (endLogger) => { return endLogger.fatal.bind(endLogger); },
};
/* eslint-disable max-len */
Object.keys(endLogging).forEach(level => {
it(`should include an "elapsed_ms" field in the last log entry with level ${level}`, done => {
Object.keys(endLogging).forEach((level) => {
it(`should include an "elapsed_ms" field in the last log entry with level ${level}`, (done) => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'trace', 'fatal');
endLogging[level](reqLogger.end())('Last message');
assert.strictEqual(dummyLogger.ops[0][1][1], 'Last message');
assert.notStrictEqual(dummyLogger.ops[0][1][0].elapsed_ms, undefined);
assert.strictEqual(typeof dummyLogger.ops[0][1][0].elapsed_ms, 'number');
assert.strictEqual(typeof(dummyLogger.ops[0][1][0].elapsed_ms), 'number');
assert.strictEqual(dummyLogger.ops[0][0], level);
done();
});
});
/* eslint-enable max-len */
it('should be augmentable through addDefaultFields', done => {
it('should be augmentable through addDefaultFields', (done) => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'trace', 'fatal');
reqLogger.end().addDefaultFields({ endFlag: true });
reqLogger.end().addDefaultFields({endFlag: true});
// Someone could do multiple operations in the meantime before
// end() logging
reqLogger.end().error('Test Augmented END', { endValue: 42 });
reqLogger.end().error('Test Augmented END', {endValue: 42});
assert.strictEqual(dummyLogger.ops[0][1][1], 'Test Augmented END');
assert.strictEqual(typeof dummyLogger.ops[0][1][0].elapsed_ms,
'number');
assert.strictEqual(typeof(dummyLogger.ops[0][1][0].elapsed_ms), 'number');
assert.strictEqual(dummyLogger.ops[0][1][0].endFlag, true);
assert.strictEqual(dummyLogger.ops[0][1][0].endValue, 42);
done();
});
it('should log an error in addition to request logs when end() called more than once',
done => {
const dummyLogger = new DummyLogger();
const reqLogger = new RequestLogger(dummyLogger, 'trace', 'fatal');
reqLogger.end().info('after first call to end()');
reqLogger.end().debug('after second call to end()');
assert.strictEqual(dummyLogger.ops.length, 3);
assert.strictEqual(dummyLogger.ops[0][0], 'info');
assert.strictEqual(dummyLogger.ops[0][1][1], 'after first call to end()');
assert.strictEqual(dummyLogger.ops[1][0], 'error');
assert.strictEqual(dummyLogger.ops[2][0], 'debug');
assert.strictEqual(dummyLogger.ops[2][1][1], 'after second call to end()');
done();
});
});
describe('Log History dumped when logging floor level reached', () => {
it('Dumping duplicates log entries', done => {
it('Dumping duplicates log entries', (done) => {
const commandHistory = ['info', 'error'];
const expectedHistory = [['info', 0], ['info', 0], ['error', 1]];
const expectedCounts = {
trace: 0,
debug: 0,
info: 2,
warn: 0,
error: 1,
fatal: 0,
};
const expectedCounts = { trace: 0, debug: 0, info: 2, warn: 0, error: 1, fatal: 0 };
runLoggingDumpTest(commandHistory, expectedHistory, expectedCounts,
done);
runLoggingDumpTest(commandHistory, expectedHistory, expectedCounts, done);
done();
});
it('Dumping Keeps logging history order', done => {
it('Dumping Keeps logging history order', (done) => {
const commandHistory = ['trace', 'info', 'debug', 'error'];
const expectedHistory = [['trace', 0], ['info', 1], ['debug', 2],
['trace', 0], ['info', 1], ['debug', 2],
['error', 3]];
const expectedCounts = {
trace: 2,
debug: 2,
info: 2,
warn: 0,
error: 1,
fatal: 0,
};
const expectedHistory = [['trace', 0], ['info', 1], ['debug', 2], ['trace', 0], ['info', 1], ['debug', 2], ['error', 3]];
const expectedCounts = { trace: 2, debug: 2, info: 2, warn: 0, error: 1, fatal: 0 };
runLoggingDumpTest(commandHistory, expectedHistory, expectedCounts,
done);
runLoggingDumpTest(commandHistory, expectedHistory, expectedCounts, done);
done();
});
it('Dumping multiple times does not re-dump already-dumped entries',
done => {
const commandHistory = ['trace', 'info', 'debug', 'error',
'warn', 'debug', 'fatal'];
const expectedHistory = [['trace', 0], ['info', 1], ['debug', 2],
['trace', 0], ['info', 1], ['debug', 2],
['error', 3], ['warn', 4], ['debug', 5],
['warn', 4], ['debug', 5],
['fatal', 6]];
const expectedCounts = {
trace: 2,
debug: 4,
info: 2,
warn: 2,
error: 1,
fatal: 1,
};
it('Dumping multiple times does not re-dump already-dumped entries', (done) => {
const commandHistory = ['trace', 'info', 'debug', 'error',
'warn', 'debug', 'fatal'];
const expectedHistory = [['trace', 0], ['info', 1], ['debug', 2],
['trace', 0], ['info', 1], ['debug', 2], ['error', 3],
['warn', 4], ['debug', 5],
['warn', 4], ['debug', 5], ['fatal', 6]];
const expectedCounts = { trace: 2, debug: 4, info: 2, warn: 2, error: 1, fatal: 1 };
runLoggingDumpTest(commandHistory, expectedHistory,
expectedCounts, done);
done();
});
runLoggingDumpTest(commandHistory, expectedHistory, expectedCounts, done);
done();
});
});
});

View File

@ -1,20 +1,19 @@
// eslint-disable-line strict
'use strict';
const assert = require('assert');
const {
generateUid, serializeUids, unserializeUids, objectCopy,
} = require('../../lib/Utils');
const Utils = require('../../lib/Utils.js');
const generateUid = Utils.generateUid;
const serializeUids = Utils.serializeUids;
const unserializeUids = Utils.unserializeUids;
const objectCopy = Utils.objectCopy;
describe('Utils: generateUid', () => {
it('generates a string-typed ID', done => {
it('generates a string-typed ID', (done) => {
const uid = generateUid();
assert.strictEqual(typeof uid, 'string',
`The generated ID is not a String (${typeof uid})`);
assert.strictEqual(typeof(uid), 'string', 'The generated ID is not a String (' + typeof(uid) + ')');
done();
});
it('generate roughly unique IDs', done => {
it('generate roughly unique IDs', (done) => {
const generated = {};
let count = 0;
for (let i = 0; i < 10000; ++i) {
@ -22,77 +21,47 @@ describe('Utils: generateUid', () => {
count = generated[uid] ? generated[uid] + 1 : 1;
generated[uid] = count;
}
Object.keys(generated).every(uid => {
assert.strictEqual(generated[uid], 1,
`Uid ${uid} was generated ${generated[uid]} `
+ 'times: It is not even remotely unique.');
return {};
Object.keys(generated).every((uid) => {
assert.strictEqual(generated[uid], 1, `Uid ${uid} was generated ${generated[uid]} times: It is not even remotely unique.`);
});
done();
});
});
describe('Utils: serializeUids', () => {
it('serializes to the expected string data', done => {
const uidList = ['FirstUID', 'SecondUID', 'ThirdUID'];
it('serializes to the expected string data', (done) => {
const uidList = [ 'FirstUID', 'SecondUID', 'ThirdUID'];
const serializedUIDs = serializeUids(uidList);
assert.strictEqual(serializedUIDs, 'FirstUID:SecondUID:ThirdUID',
'Serialized UID List should match expected value.');
assert.strictEqual(serializedUIDs, 'FirstUID:SecondUID:ThirdUID', 'Serialized UID List should match expected value.');
done();
});
it('unserializes the expected number of UIDs', done => {
const refUidList = ['FirstUID', 'SecondUID', 'ThirdUID'];
it('unserializes the expected number of UIDs', (done) => {
const refUidList = [ 'FirstUID', 'SecondUID', 'ThirdUID'];
const unserializedUIDs = unserializeUids('FirstUID:SecondUID:ThirdUID');
assert.deepStrictEqual(unserializedUIDs, refUidList,
'Unserialized UID List should match expected value.');
assert.deepStrictEqual(unserializedUIDs, refUidList, 'Unserialized UID List should match expected value.');
done();
});
});
describe('Utils: objectCopy', () => {
it('copies all the properties from source to target object', done => {
it('copies all the properties from source to target object', (done) => {
const target = { foo: 'bar' };
const source = { id: 1, name: 'demo', value: { a: 1, b: 2, c: 3 } };
const result = {
foo: 'bar',
id: 1,
name: 'demo',
value: { a: 1, b: 2, c: 3 },
};
const result = { foo: 'bar', id: 1, name: 'demo', value: { a: 1, b: 2, c: 3 } };
objectCopy(target, source);
assert.deepStrictEqual(target, result,
'target should have the same properties as source');
assert.deepStrictEqual(target, result, 'target should have the same properties as source');
done();
});
it('copies all the properties from multiple sources to target object',
done => {
const target = { foo: 'bar' };
const source1 = {
id: 1,
name: 'demo1',
value: { a: 1, b: 2, c: 3 },
};
// eslint-disable-next-line camelcase
const source2 = {
req_id: 2,
method: 'test',
err: { code: 'error', msg: 'test' },
};
const result = {
foo: 'bar',
id: 1,
name: 'demo1',
value: { a: 1, b: 2, c: 3 },
// eslint-disable-next-line camelcase
req_id: 2,
method: 'test',
err: { code: 'error', msg: 'test' },
};
objectCopy(target, source1, source2);
assert.deepStrictEqual(target, result,
'target should have the same properties as source');
done();
});
it('copies all the properties from multiple sources to target object', (done) => {
const target = { foo: 'bar' };
const source1 = { id: 1, name: 'demo1', value: { a: 1, b: 2, c: 3 } };
const source2 = { req_id: 2, method: 'test', err: { code: 'error', msg: 'test' } };
const result = { foo: 'bar', id: 1, name: 'demo1', value: { a: 1, b: 2, c: 3 },
req_id: 2, method: 'test', err: { code: 'error', msg: 'test' }};
objectCopy(target, source1, source2);
assert.deepStrictEqual(target, result, 'target should have the same properties as source');
done();
});
});

View File

@ -1,17 +0,0 @@
#!/usr/bin/env node
// Convert string args into primitive value
const fromStr = (str, primitive) => (str === `${primitive}` ? primitive : str);
const date = fromStr(process.argv[2], undefined);
const exitCode = fromStr(fromStr(process.argv[3], null), undefined);
const { stderrUtils } = require('../../../../index');
stderrUtils.catchAndTimestampStderr(
date ? () => date : undefined,
exitCode,
);
process.emitWarning('TestWarningMessage');
// This will print warning after printing error before exit
throw new Error('TestingError');

View File

@ -1,23 +0,0 @@
#!/usr/bin/env node
// Convert string args into primitive value
const fromStr = (str, primitive) => (str === `${primitive}` ? primitive : str);
const date = fromStr(process.argv[2], undefined);
const exitCode = fromStr(fromStr(process.argv[3], null), undefined);
const promise = fromStr(process.argv[4], true);
const { stderrUtils } = require('../../../../index');
stderrUtils.catchAndTimestampUncaughtException(
date ? () => date : undefined,
exitCode,
);
// Executed if process does not exit, process is in undefined behavior (bad)
// eslint-disable-next-line no-console
setTimeout(() => console.log('EXECUTED AFTER UNCAUGHT EXCEPTION'), 1);
if (promise === true) {
Promise.reject();
} else {
throw new Error('TestingError');
}

View File

@ -1,38 +0,0 @@
#!/usr/bin/env node
// Convert string args into primitive value
const fromStr = (str, primitive) => (str === `${primitive}` ? primitive : str);
const date = fromStr(process.argv[2], undefined);
const name = fromStr(process.argv[3], undefined);
const code = fromStr(process.argv[4], undefined);
const detail = fromStr(process.argv[5], undefined);
const { stderrUtils } = require('../../../../index');
stderrUtils.catchAndTimestampWarning(
date ? () => date : undefined,
);
const warning = new Error('TestWarningMessage');
if (name) warning.name = name;
if (code) warning.code = code;
if (detail) warning.detail = detail;
process.emitWarning(warning);
/*
Examples:
(node:203831) Error: TestWarningMessage
at Object.<anonymous> (catchWarning.js:15:17)
...
at node:internal/main/run_main_module:22:47
Above Warning Date: 2024-06-26T16:32:55.505Z
(node:205151) [TEST01] CUSTOM: TestWarningMessage
at Object.<anonymous> (catchWarning.js:15:17)
...
at node:internal/main/run_main_module:22:47
Some additional detail
Above Warning Date: Tue, 31 Dec 2024 10:20:30 GMT
*/

View File

@ -1,309 +0,0 @@
const assert = require('assert');
const { execFile } = require('child_process');
const stderrUtils = require('../../lib/stderrUtils');
/** Simple regex for ISO YYYY-MM-DDThh:mm:ss.sssZ */
// eslint-disable-next-line max-len
const defaultDateRegex = /\d{4}-[01]\d-[0-3]\dT[0-2]\d:[0-5]\d:[0-5]\d\.\d+(?:[+-][0-2]\d:[0-5]\d|Z)/;
// eslint-disable-next-line valid-jsdoc
/** another format: Tue, 31 Dec 2024 10:20:30 GMT */
const customDate = () => new Date('2024-12-31T10:20:30.444Z').toUTCString();
describe('stderrUtils', () => {
const errStackRegex = /Error: TestingError\n(?:.*\sat\s.*\n)+/;
describe('defaultTimestamp', () => {
it('should match ISO format', () => {
assert.match(stderrUtils.defaultTimestamp(), defaultDateRegex);
});
});
describe('printErrorWithTimestamp', () => {
let stderrText;
const originalStderrWrite = process.stderr.write;
const mockedStderrWrite = text => { stderrText = text; return true; };
const err = new Error('TestingError');
const origin = 'uncaughtException';
beforeEach(() => {
stderrText = undefined;
process.stderr.write = mockedStderrWrite;
});
afterEach(() => {
process.stderr.write = originalStderrWrite;
stderrText = undefined;
});
it(
'should write to stderr with current date, origin and stacktrace',
() => {
const written = stderrUtils
.printErrorWithTimestamp(err, origin);
assert.strictEqual(written, true);
const [firstLine, errStack] = stderrText.split(':\n');
const [errDate, errOrigin] = firstLine.split(': ');
assert.match(errDate, defaultDateRegex);
assert.strictEqual(errOrigin, origin);
assert.strictEqual(errStack, `${err.stack}\n`);
},
);
it(
'should write to stderr with custom date, origin and stacktrace',
() => {
const written = stderrUtils
.printErrorWithTimestamp(err, origin, customDate());
assert.strictEqual(written, true);
const [firstLine, errStack] = stderrText.split(':\n');
const [errDate, errOrigin] = firstLine.split(': ');
assert.strictEqual(errDate, customDate());
assert.strictEqual(errOrigin, origin);
assert.strictEqual(errStack, `${err.stack}\n`);
},
);
});
const execOptions = {
cwd: __dirname,
// Subprocess should always stop alone
// But just in case, kill subprocess after 500ms.
// Leave enough time for `nyc` that runs slower.
timeout: 500,
};
// Execute in another process to notice the process exit
// Therefore, looks more like a functional test
const timeoutHint = (ms, retries) =>
`Test fixture process timed out after ${ms}ms with ${retries} retries.\n` +
'Due to nyc coverage first run slowing down process.\nIncrease execOptions.timeout to fix';
describe('catchAndTimestampUncaughtException', () => {
[
{ desc: 'with default date' },
{ desc: 'with custom date', date: customDate() },
{ desc: 'with custom exitCode 42', exitCode: 42 },
{ desc: 'without exit on uncaught exception', exitCode: null },
{ desc: 'for unhandled promise', promise: true },
].forEach(({
desc, date, exitCode, promise,
}) => describe(desc, () => {
/** for before all hook that doesn't support this.retries */
let retries = 4;
let err;
let stdout;
let stderr;
let errStack;
let errDate;
let errOrigin;
before('run process catchUncaughtException', function beforeAllHook(done) {
execFile(
'./fixtures/stderrUtils/catchUncaughtException.js',
[`${date}`, `${exitCode}`, `${promise}`],
execOptions,
(subErr, subStdout, subStderr) => {
if (subErr?.killed) {
retries--;
if (retries <= 0) {
assert.fail(timeoutHint(execOptions.timeout, retries));
}
execOptions.timeout *= 2;
return beforeAllHook(done);
}
err = subErr;
stdout = subStdout;
stderr = subStderr;
let firstLine;
[firstLine, errStack] = stderr.split(':\n');
[errDate, errOrigin] = firstLine.split(': ');
done();
},
);
});
if (exitCode === null) {
it('should not be an error (or timeout)',
() => assert.ifError(err));
it('should have stdout (printed after uncaught exception)',
() => assert.match(stdout,
/^.*EXECUTED AFTER UNCAUGHT EXCEPTION(?:.|\n)*$/));
} else {
it('should be an error',
() => assert.ok(err));
it(`should have exitCode ${exitCode || 1}`,
() => assert.strictEqual(err.code, exitCode || 1));
it('should have empty stdout',
() => assert.strictEqual(stdout, ''));
}
it('should have stderr',
() => assert.ok(stderr));
it('should have date in stderr first line',
() => (date
? assert.strictEqual(errDate, date)
: assert.match(errDate, defaultDateRegex)));
it('should have origin in stderr first line',
() => (promise === true
? assert.strictEqual(errOrigin, 'unhandledRejection')
: assert.strictEqual(errOrigin, 'uncaughtException')));
if (!promise) {
it('should have stack trace on stderr',
() => assert.match(errStack, errStackRegex));
}
}));
});
describe('catchAndTimestampWarning (also tests node onWarning)', () => {
[
{ desc: 'with default date' },
{ desc: 'with custom date', date: customDate() },
{ desc: 'with deprecation warning', name: 'DeprecationWarning' },
{
desc: 'with custom warning',
name: 'CUSTOM',
code: 'TEST01',
detail: 'Some additional detail',
},
].forEach(({
desc, date, name, code, detail,
}) => describe(desc, () => {
/** for before all hook that doesn't support this.retries */
let retries = 4;
let err;
let stdout;
let stderr;
before('run process catchWarning', function beforeAllHook(done) {
execFile(
'./fixtures/stderrUtils/catchWarning.js',
[`${date}`, `${name}`, `${code}`, `${detail}`],
execOptions,
(subErr, subStdout, subStderr) => {
if (subErr?.killed) {
retries--;
if (retries <= 0) {
assert.fail(timeoutHint(execOptions.timeout, retries));
}
execOptions.timeout *= 2;
return beforeAllHook(done);
}
err = subErr;
stdout = subStdout;
stderr = subStderr;
done();
},
);
});
it('should not be an error (or timeout)',
() => assert.ifError(err));
it('should have empty stdout',
() => assert.strictEqual(stdout, ''));
it('should have stderr',
() => assert.ok(stderr));
it('should have message on stderr first line, then stack trace',
() => assert.match(stderr,
/^.*TestWarningMessage\n(?:\s+at\s.*\n)+/));
if (code) {
it('should have code on stderr first line',
() => assert.match(stderr, new RegExp(`^.*[${code}]`)));
}
if (name) {
it('should have name on stderr first line',
() => assert.match(stderr, new RegExp(`^.*${name}:`)));
}
if (detail) {
it('should have detail on stderr',
() => assert.match(stderr, new RegExp(`.*${detail}.*`)));
}
it(`should have ${date ? 'custom' : 'default'} date on stderr`,
() => assert.match(stderr, new RegExp(
`\nAbove Warning Date: ${
date || defaultDateRegex.source}\n`,
)));
}));
});
describe('catchAndTimestampStderr', () => {
[
{ desc: 'with default date' },
{ desc: 'with custom date', date: customDate() },
{ desc: 'with exit code', exitCode: 42 },
].forEach(({
desc, date, exitCode,
}) => describe(desc, () => {
/** for before all hook that doesn't support this.retries */
let retries = 4;
let err;
let stdout;
let stderr;
before('run process catchStderr', function beforeAllHook(done) {
execFile(
'./fixtures/stderrUtils/catchStderr.js',
[`${date}`, `${exitCode}`],
execOptions,
(subErr, subStdout, subStderr) => {
if (subErr?.killed) {
retries--;
if (retries <= 0) {
assert.fail(timeoutHint(execOptions.timeout, retries));
}
execOptions.timeout *= 2;
return beforeAllHook(done);
}
err = subErr;
stdout = subStdout;
stderr = subStderr;
done();
},
);
});
it('should be an error',
() => assert.ok(err));
it(`should have exitCode ${exitCode || 1}`,
() => assert.strictEqual(err.code, exitCode || 1));
it('should have empty stdout',
() => assert.strictEqual(stdout, ''));
it('should have stderr',
() => assert.ok(stderr));
// 2024-06-26T15:04:55.364Z: uncaughtException:
// Error: TestingError
// at Object.<anonymous> (catchStderr.js:16:7)
// at node:internal/main/run_main_module:22:47
it('should have error date, origin and stacktrace in stderr',
() => assert.match(stderr,
new RegExp(`${date || defaultDateRegex.source
}: uncaughtException:\n${errStackRegex.source}`)));
// (node:171245) Warning: TestWarningMessage
// at Object.<anonymous> (catchStderr.js:14:9)
// at node:internal/main/run_main_module:22:47
// Above Warning Date: 2024-06-26T15:04:55.365Z
it('should have warning with stacktrace in stderr', () => {
const trace = 'Warning: TestWarningMessage\n(?:\\s+at\\s.*\n)+';
const detail = `(?:.|\n)*?(?<=\n)Above Warning Date: ${
date || defaultDateRegex.source}\n`;
assert.match(stderr,
new RegExp(`${trace}${detail}`));
});
}));
});
});