Giter Club home page Giter Club logo

werelogs's Introduction

WereLogs

![Scality CI][badgepriv]

This repository provides a NodeJS Library that aims to be an efficient logging library, reducing as much as possible the need to compute anything in NodeJS, and focusing on a simple I/O scheme. The goal here is to make the most of NodeJS's strengths, but relying on its I/O capacities, and avoiding any form of computation that is known to not be advantageous in Node.

Contributing

In order to contribute, please follow the Contributing Guidelines.

Installing the Library

In order to install WereLogs, you can use NPM with github's HTTP url, and save it in your own package.json:

$> npm i --save scality/werelogs

As the repository is currently private, you will need to provide your username and your password, or use the git+ssh protocol with a properly configured environment, or use the git+https protocol with your username and cleartext password in the URL (which I absolutely don't recommend for security reasons).

Using the Library

Werelogs is a logging library that provides both per-request and per-module logging facilities, through the intermediary of the per-module Logger that is the default export.

Werelogs may be configured only once throughout your application's lifetime, through the configuration options available in the per-module logger constructor.

The per-module Logger object is used to log relevant events for a given module.

The RequestLogger object is the one you want to use for any logging operation related to an ongoing request, so you will have to pass it to any function that requires it.

All logging methods (trace, debug, info, warn, error and fatal) follow the same prototype and usage pattern. They can take up to two parameters, the first one, mandatory, being a string message, and the second one, optional, being an object used to provide additional information to be included in the log entry.

The RequestLogger also provides a way to include some attributes in the JSON by default for all subsequent logging calls, by explicitly inputting them only once for the whole request's lifetime through the method addDefaultFields.

As the RequestLogger is a logger strongly associated to a request's processing operations, it provides a builtin facility to log the elapsed time in ms of the said processing of the request. This is done through a specific logging method, end that returns a prepared logging object. Using this returned object with the usual logging methods will automatically compute the elapsed time from the instantiation of the RequestLogger to the moment it is called, by using an internal hi-res time generated at the instantiation of the logger.

import Logger from 'werelogs';

/*
 * Here, configure your WereLogs Logger at a global level
 * It can be instantiated with a Name (for the module), and a config options
 * Object.
 *
 * This config options object contains a log level called 'level', a log
 * dumping threshold called 'dump'. The only unnecessary
 * field is the 'level' of each individual stream, as werelogs is managing
 * that on its own.
 *
 * All request loggers instantiated through this Logger will inherit its
 * configuration.
 */
const log = new Logger(
    'SampleModule',
    {
        level: 'debug',
        dump: 'error',
    }
);

/*
 * First, you can use the Logger as a module-level logger, logging events
 * that happen at the module's level.
 *
 * The API of the module-level logger is the same as the API of the request
 * Logger.
 */
log.info('Application started.');
log.warn('Starting RequestLogging...', {'metadata': new Date()});

doSomething(reqLogger) {
    /*
     * Let's add some kind of client-related data as default attributes first
     */
    reqLogger.addDefaultFields({ clientIP: '127.0.0.1',
                                 clientPort: '65535',
                                 clientName: 'Todd'});

    /*
     * Then, you can log some data, either a string or an object, using one of
     * the logging methods: 'trace', 'debug', 'info', 'warn', 'error', or
     * 'fatal'.
     */
    reqLogger.info('This is a string log entry');
    // This example provides additional information to include into the JSON
    reqLogger.info('Placing bet...',
                   { date: new Date().toISOString(),
                     odds: [1, 1000],
                     amount: 20000,
    });
}

function processRequest() {
    /*
     * Now, for one specific request, we need to get a request-specific logger
     * instance. It can be called without a request ID, and will then generate
     * one for you. Otherwise you can give it a string id (no specific format
     * required) or a list of string ids (that can allow request-scoping on a
     * distributed system)
     */
    const reqLogger = log.newRequestLogger();

    /* you need to provide your logger instance to the code that requires it,
     * as it is not a module-wide object instance */
    doSomething(reqLogger, ...);

    ...

    /*
     * Planning for some specific data to be included in the last logging
     * request, you could use the addDefaultFields of the end()'s object:
     */
    reqLogger.end().addDefaultFields({method: 'GET', client: client.getIP()})

    /*
     * This call will generate a log entry with an added elapsed_ms
     * field. This object can only be used once, as it should only be used for
     * the last log entry associated to this specific RequestLogger.
     * This call will be reusing potential data fields previously added through
     * end().addDefaultFields().
     */
    reqLogger.end().info('End of request.', { status: 200 });
}

Known Issues

In order to find out the known issues, it is advised to take a look at the project's github page. There, you should be able to find the issues, tagged with the releases they are impacting, whether they're open or closed.

werelogs's People

Contributors

alexandre-merle avatar bert-e avatar bourgoismickael avatar dependabot[bot] avatar dvasilas avatar erwan-b avatar francoisferrand avatar giorgioregni avatar guillaumegomez avatar harperscality avatar ironman-machine avatar jduarter avatar jmunoznaranjo avatar jonathan-gramain avatar katherinelaue1 avatar lamphamsy avatar mathieucassagne avatar philipyoo avatar rachedbenmustapha avatar rahulreddy avatar tcarmet avatar thibaultriviere avatar tmacro avatar vrancurel avatar williamlardier avatar

Stargazers

 avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar

Watchers

 avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar

werelogs's Issues

Provide easy-to-use API to log elapsed-time of an operation

For most services, one might want to log the elapsed time of an operation when finishing it.
In order to provide this in an easy-to-use fashion, I've been thinking of a new logging method, 'end', that would use a configured logging level for the ending log entries; and that would use the internal hrtime to compute the elapsed time that it could automatically add to the added field data.
ie:

    const log = new Werelogs('service', { end: 'info' });
    ...
    var logger = log.newRequestLogger();
    ...
    log.end('message', {field: 0});

Failure during use of the logger

/home/michael/ironman/s3/node_modules/werelogs/target/lib/RequestLogger.js:247
        fields.hrtime = JSON.stringify(process.hrtime());
                      ^

TypeError: Cannot assign to read only property 'hrtime' of SignatureDoesNotMatch
    at RequestLogger.log (/home/michael/ironman/s3/node_modules/werelogs/target/lib/RequestLogger.js:247:23)
    at RequestLogger.error (/home/michael/ironman/s3/node_modules/werelogs/target/lib/RequestLogger.js:199:21)
    at Object.authRes (api.js:26:21)
    at headerAuthCheck.js:58:24
    at rcvVaultV2Sig (vault.js:56:24)
    at Object.backend.verifySignatureV2 (backend.js:34:20)
    at Object.vault.authenticateV2Request (vault.js:41:16)
    at Object.headerAuthCheck (headerAuthCheck.js:50:11)
    at auth (auth.js:13:20)
    at Object.callApiMethod (api.js:24:9)

Stack trace

How to reproduce :

  1. be patient
  2. Put 10 hours of data
  3. Hope

<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0xb4870337399
1: log [/home/ironman/IronMan-MetaData/node_modules/werelogs/target/lib/RequestLogger.js:~151] [pc=0x1e9a7f024d0e](this=0x2eca71642131 <a RequestLogger with map 0x1d9ba9f31759>,level=0xb48703a4ec1 <String[5]: debug>,msg=0xdf6be6e7cd1 <String[24]: Request: new RaftRequest)
2: debug [/home/ironman/IronMan-MetaData/node_modules/werelogs/target/lib/RequestLogger.js:~115] [pc=0x1e9a7efabc26...

Use process.hrtime to calculate timestamp

Since timestamp generation was a concern (e.g. new Date() vs Date.now() optimization), we could generate timestamp when a new request logger is created and record the process.hrtime(). We could use the hrtime calculate the milliseconds diff for the log entry and add it to the timestamp. This way we don't have to call Date.now() on every log entry.

For example, on a new request logger

// inside request logger
const reqTimestamp = Date.now();
const start = process.hrtime();

...

// inside doLog function
const elapsedMs = Math.floor(process.hrtime(start)[1] / 1000000); // convert nano to milli
const logTimestamp = reqTime + elapsedMs;

log verbosity should be dynamically changeable

Log verbosity is currently controlled by a static configuration file.

There is a need to be able to change to change the log verbosity without having to restart the daemon.

Having to restart mission critical service to investigate a problem is a major operational pain. When this is happening, we are already in a position where our negocation power with the customer is limited.

Library can't be used using true ES6 or typescript

Since the Logger class is exported neither as a default nor as in an object, it can't be picked up by an ES6 import matching the ES6 implementation (i.e. not Babel, which is more permissive) nor a typescript module.

This can be fixed easily, but will require an update of some packages depending on it (either the ES5 modules (changing the export to module.exports.default = Logger; or everything (using module.exports = { Logger };)).

Edit: the first solution doesn't play too nice with Babel, sadly.

compute the time inside the Logger

Actually, we compute the time field only for the RequestLogger, should we compute also for the Logger itself, in order to have proper log timeline ? :)

implicit sensible default configuration for non mandatory fields & proper error during configuration parsing

Metadata has a configuration file.
It now currently read as follows :

{
    "address": "127.0.0.1",
    "dbPath": "/tmp/databases",
    "port": 9000,
    "map" : [
        "deployment_metadata_1:9042",
        "deployment_metadata_2:9042",
        "deployment_metadata_3:9042",
        "deployment_metadata_4:9042",
        "deployment_metadata_5:9042"
    ],
    "repdPorts": [9043, 9199],
    "log": {
        "host": "127.0.0.1",
        "port": 5505,
        "level": "info",
        "dump": "error"
    }
}

The only two fields that should be specified are : address and map.

Currently the complete set of fields should be specified (log, repdPorts, port, dbPath). Otherwise the software fails to start.

Here is the error message generated when the log is missing in the configuration :

/home/ironman/IronMan-Vault/node_modules/werelogs/target/lib/LogLevel.js:22
        throw new RangeError(`Invalid logging level: ${ level } is neither` + ` ${ logLevels.join(', ') }.`);
        ^

RangeError: Invalid logging level: undefined is neither trace, debug, info, warn, error, fatal.
    at Object.throwIfInvalid (/home/ironman/IronMan-Vault/node_modules/werelogs/target/lib/LogLevel.js:22:15)
    at new Logger (/home/ironman/IronMan-Vault/node_modules/werelogs/target/lib/Logger.js:55:22)
    at createLogger (/home/ironman/IronMan-Vault/node_modules/IronMan-MetaData/lib/server/Logging.js:5:12)
    at new DBD (/home/ironman/IronMan-Vault/node_modules/IronMan-MetaData/lib/server/DBD.js:28:25)
    at new Vault (/home/ironman/IronMan-Vault/lib/Vault.js:284:23)
    at Object.<anonymous> (/home/ironman/IronMan-Vault/vaultd.js:4:15)
    at Module._compile (module.js:435:26)
    at Object.Module._extensions..js (module.js:442:10)
    at Module.load (module.js:356:32)
    at Function.Module._load (module.js:311:12)

Would it be possible to get a somewhat clearer message ? (e.g. from the above it is not obvious why the software fails to run and it is only wrong configuration). A clear error message in the logs is expected from any reason that causes a failure in parsing the configuration.

In addition, all the fields except address and map would benefit from sensible default. If the log is not present in the configuration, would it be possible to use sensible default values ?

Finally in the future for backwards compatibility of the configuration could fields added to the configuration have a sensible default value that would allow the software to run even if these new fields are missing in the configuration ?

DBD lacks a way to retrieve the metadata configuration file

It looks like master for DBD is ignoring the environment variable METADATA_CONFIG_FILE.

This is a problem as vault is loading DBD.

The default configuration provided within DBD is incorrect.

Vault startup fails with :

> [email protected] start /home/ironman/IronMan-Vault
> node vaultd.js

/home/ironman/IronMan-Vault/node_modules/werelogs/target/lib/LogLevel.js:22
        throw new RangeError(`Invalid logging level: ${ level } is neither` + ` ${ logLevels.join(', ') }.`);
        ^

RangeError: Invalid logging level: undefined is neither trace, debug, info, warn, error, fatal.
    at Object.throwIfInvalid (/home/ironman/IronMan-Vault/node_modules/werelogs/target/lib/LogLevel.js:22:15)
    at new Logger (/home/ironman/IronMan-Vault/node_modules/werelogs/target/lib/Logger.js:55:22)
    at createLogger (/home/ironman/IronMan-Vault/node_modules/IronMan-MetaData/lib/server/Logging.js:5:12)
    at new DBD (/home/ironman/IronMan-Vault/node_modules/IronMan-MetaData/lib/server/DBD.js:28:25)
    at new Vault (/home/ironman/IronMan-Vault/lib/Vault.js:284:23)
    at Object.<anonymous> (/home/ironman/IronMan-Vault/vaultd.js:4:15)
    at Module._compile (module.js:435:26)
    at Object.Module._extensions..js (module.js:442:10)
    at Module.load (module.js:356:32)
    at Function.Module._load (module.js:311:12)

Module logger writes undefined to log message

Here's my current usage. I have am using module logger as

logger.info(`Serving web content at ${addr.address}${addr.port} - PID: ${process.pid}`);
[2016-02-02T20:28:14.971Z]  INFO: S3/65420 on Rahuls-MacBook-Pro.local: undefined 'Serving web content at ::8000 - PID: 65420'

It will remove undefined if I log as

logger.info(`Serving web content at ${addr.address}${addr.port} - PID: ${process.pid}`, {});
[2016-02-02T20:33:28.814Z]  INFO: S3/65553 on Rahuls-MacBook-Pro.local: Serving web content at ::8000 - PID: 65553

Fatal logs to stderr too ?

I open this to discuss about logging the fatal errors to stderr too, that way we can still have in stdout the log, but we also have it in stderr, for the log beeing more visible

Add a 'errorState' flag into the Request Logger.

Currently, werelogs will dump all the history of one request when reaching the dump threshold level with a log entry. Then, if when unxinding the code, new log entries are entered, with a higher level than the dump threshold, each of them will trigger a full history dump again.

Some kind of flag should empty out the history of the request logger when the dump threshold is reached, and also prevent further log entries over the dump threshold from dumping again.

Werelogs 2.0

  • Suppress CPU intensive calls
  • Externalize log rotation and communication to ELK

Add capacity to log per module

In order to provide complete coverage of logging use case, we cannot exclude logging outside of a request.
For instance, a starting daemon may want to notify it started listening on a port, but that can't be done within a request.

As such, we should provide a default Module Logger that would allow logging directly through the logger by default.

Provide a single configuration point for the whole library

Currently, if an user wants to instanciate multiple ModuleLoggers; or instanciate RequestLoggers from different files, he has to reproduce the configuration code for werelogs wherever he wishes to use it, instead of configuring it once and for all, and then only reuse the logging system as-is.

We need to improve this, for usability and future readability.

CI fails on linter check

This is the output on CI


/home/ubuntu/werelogs/index.js
  0:0  error  Cannot find module 'babel-eslint'

I am not sure how this worked as we don't see babel-eslint in package.json but it's mentioned as
parser in eslintrc.

Add implicit dump until level

Typical configuration for logging is

{
   "logLevel": "info",
   "dumpLevel": "error"
}

This would make INFO level log print twice.

Proposed solution:

When dumping logs print until (logLevel - 1) level i.e. in this example, all log entries with levels ERROR, TRACE, DEBUG will be printed when dumping the logs and not INFO.

Make sure that the logs won't make a huge failure worse

As described by @rachedbenmustapha in the PR #1 , We need to design some kind of fallback behavior for whenever enough errors occur simultaneously (but slowly) to fill the memory with log entries.

We need to make sure that the log system won't become a worsening factor, and that it won't hog all the memory for itself due to bad design decisions.

The first (and current) version shall be simple, but we need to think about a solution for the long-term.

Suggestion: remote ip in the logs

it would be nice to have the ip of the client (of the remote S3 client, of the remote vault client, of the remote bucketd client, of the remote repd client) in the log.

Make sure that the user won't unknowingly overwrite some internal data fields.

When a user logs something with additional data, using an internal data field has the bad behavior to overwrite a reserved internal key.
for instance:

reqLogger.info('text message', { name: 'pouet' });

here, the reserved internal field "name" will be overwritten.

We need to make sure this cannot happen in a default setting.

Such a behavior must be thought about for the default fields too.

Cleanup: rework doLogIO in RequestLogger

doLogIO currently takes a log level and a log entry. That being said, the log level should be part of the entry, making the first parameter useless.
This should be reworked and cleaned-up as soon as possible.

Unable to instantiate logger

I can't instantiate the logger because node is not happy with the current ES5 way to requiring things. Basically it should be

require('./es6-compat.js');

module.exports = require('./lib/Logger.js');

Improve Logging interface by capturing all incoming arguments

The logging methods only expect one argument in the current version. This means that any extra argument is lost in the logging process, while it should at least be kept within an object.

We should fix this, so that no logging data is lost due to mis-use of the logging interface.

Dynamically change log level by sending a signal

It would be very useful on production system to be able to change log level to debug when receiving a SIGUSR1 signal and reverting to the configured log level when receiving that signal again.
Maybe SIGUSR2 to go intro trace mode as well.

This way we could dynamically switch between different log levels on a process without restarting it.

Fixup JSDoc comments's params field

JSDoc comments concerning function parameters should be written as:
@params {Type} varname comment

Currently, a big part of the code has been written inverting the order of the var's name and its type. This should be fixed.

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    ๐Ÿ–– Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. ๐Ÿ“Š๐Ÿ“ˆ๐ŸŽ‰

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google โค๏ธ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.