I want to add a unique request id to all the logs that gets generated while serving a particular request.

I'm using expressjs and I've already figured out the request id generation part.

I tried to use the setGlobal method (I was naive 😞) but the value gets over written as soon as the server receives another request while the current request is still under operation which is normal.

Is there a way to pass the custom context related information to the logs?

Hello @TomFrost and contributors,

Wondering if you'd be open to taking on another dependency and changing the default json formatter to use json-stringify-safe to protect crashing the process when trying to stringify a circular structure?

I'm willing to make a PR if this is something you'd like.

Thanks 👍

Senario:
A site is kept alive for a long time or it tries try-catch over and over again and logging all kind of error.
It will produce file log's of Gigabytes

It would be sweet if I could configure to have something like a limited history of 5000 set of logs or lines or bytes

I am wrapping Bristol and applying arguments every time log() is called. This adds a line to the stack trace, which Bristol picks up and uses as the origin.

Problem

    at Logger.log (/files/logger-wrapper/index.js:17:28) <-- my wrapper
    at Logger.(anonymous function) [as debug] (/stuff/bristol/src/Bristol.js:202:20) <-- bristol logger
    at /stuff/app.js:162:12 <-- thing that actually calls the log() function

Proposal

Make _getOrigin() look for its own file name and use the line after that.

  _getOrigin() {
    Error.prepareStackTrace = arrayPrepareStackTrace
    const stack = (new Error()).stack
    let origin = null
    for (let i = 1; i < stack.length; i++) {
      const file = stack[i].getFileName()
      // find this file, 'Bristol.js', then use the next line in the stack
      if (file === __filename) {
        origin = {
          file: stack[i + 1].getFileName(),
          line: stack[i + 1].getLineNumber().toString()
        }
        break
      }
    }
    Error.prepareStackTrace = originalPrepareStackTrace
    return origin
  }

Let me know if you agree with this approach and if you want it turned into a PR. Thanks @TomFrost !

It's extremely common to implement Bristol (and most loggers) in a project by loading and configuring it in a JS file within a project, and then requiring that file throughout the project to make calls to the logger. This adds boilerplate code to every project, forcing the programmer to come up with their own scheme to map between configurations and the chained configuration interface of Bristol. This also puts a tedious blockade in 12Factor projects, where all configuration should be able to be changed by env vars.

In Cryptex, I implemented a system where the library could be transparently configured at load time, using zero code, just by setting the appropriate environment variables. I'd like Bristol to have a similar solution, recognizing that:

• some features in Bristol require writing JavaScript functions and can never be fully replicated in env vars
• it will likely remain a best practice to wrap Bristol in another JS file even if code-level configuration is not needed, in case it is later I think enough of this is solved that this may not be expressly needed for common use cases
• it is infeasible (as in: possible but terribly ugly/unintuitive) to configure more than one target on more than one Bristol instance in this manner solved

Given the above, I still find a lot of worth in pre-written env var integration due to the amount of configuration mapping code that will reduce for the end-user, and paving the way for Bristol to take more control over its configuration options and processes in the future.

With that said, there is a significant challenge that comes from making this configuration style functional: custom targets and formatters need to be added by the library user in the code, but Bristol is loaded and will need to be configured before they are added.

And so, I propose adding a layer to the search chain for Bristol modules. If someone adds a target or formatter foo, Bristol will first attempt to load a built-in target or formatter named foo, and if that fails, it will attempt to require(process.env.BRISTOL_MODULES_DIR + '/foo), and if that fails, it will attempt to require('bristol-foo'). If someone tries adding a target or formatter that starts with a dot or slash, Bristol will assume it's a path and require() it with no modification.

This allows custom targets and formatters to be discovered without requiring code to "install" them before a new target is configured.

@MarkHerhold, I'm particularly interested in your thoughts on this as the maintainer of Palin. This would likely require publishing that formatter to a new NPM package name, but would reduce the code involved in configuring Bristol to use it.

I've found a wrong behaviour when logging arrays.

I'm logging an object like this:

{ name: 'string',
  energy: 
   { isConsistent: true,
     lastUpdate: '2015-05-20T17:30:00.000Z', },
  hourly: 
   [ 1 value per hour since same day 00:00 ] }

Using the human formatter the object is printed this way:

[2015-05-20 18:24:39] DEBUG:  (/.../index.js:50)
  name: string
  energy: 
      {
          "isConsistent": true,
          "lastUpdate": "2015-05-20T17:30:00.000Z",
      }
  hourly: [object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object]

The problem seems to be human.js#L68 where you check for string [object Object] while the string coming from toString() is like [object Object],[object Object],....

Using util.inspect works fine, and is my current workaround ( I defined a custom formatter with only that line changed ). There is some specific reason why has not been used util.inspect? There is some other way in which I can resolve this issue ( apart from stringifing the content before loggin in)?

Thank you for this library and you support :)

I've set up bristol for production with file target and human formatter. I didn't use console target as it was said in Bristol docs to be non async and blocking. But what nodejs docs say is:

The console functions are usually asynchronous unless the destination is a file

So is this still the case and console target should be avoided in prod? I used to use pm2 log management and now when I don't log to console it's getting pretty useless.

Hi,

Getting an error when trying to save to a file. Logging to console works, but I get an error after I add the following line to app.js (I'm using Express v4.13.4 and Node.js v5.10.1):

log.addTarget('file', path.join(__dirname, 'logs', 'errors.log'));

When I try to log something, I get this error in the console:

TypeError: path must be a string
    at TypeError (native)
    at Object.fs.open (fs.js:575:11)
    at WriteStream.open (fs.js:1918:6)
    at new WriteStream (fs.js:1904:10)
    at Object.fs.createWriteStream (fs.js:1859:10)
    at getStream (node_modules\bristol\lib\targets\file.js:23:22)
    at Function.log (node_modules\bristol\lib\targets\file.js:40:12)
    at Bristol._logToTarget (node_modules\bristol\lib\Bristol.js:342:10)
    at node_modules\bristol\lib\Bristol.js:150:8
    at Array.forEach (native)

The folder exists, and I tried changing the path to a string, but still getting the error. Could I be missing something else?

Hi, I'm curious about whether it is "proper" to just write a middleware function(req, res, next) that logs whatever I want about the request with Bristol, and then replace express morgan with this function.

@TomFrost Love Bristol, been using it for a long time.

I recently came across a need to obfuscate my file paths. I found that this was relevant for live demos both for the sake of security and clarity and that it would be helpful in certain production deployments to reduce the logging payload when I already know the executable path.

I'd like to see an option on the Bristol constructor to support relative pathing from process.cwd(). Using this setting the logged stack trace path would be limited to the folders in a given project directory assuming that it was the current working directory when the process was started.

let logger = new Bristol({
    relativeStackTracePaths: true // default: false (current behavior)
});

Would end up using:

path.relative(process.cwd(), filePath);

I wouldn't worry about handling the cases of starting a node process from a different directory.

I've modified a version of Bristol and can PR in the fix if you think it would be appropriate/useful. With respect to performance, this would add a single if statement in every log event unless you wanted to maintain two path retrieval functions and dynamically set them on the Bristol instance.

I have not tested how this affects globally linked modules, but based on my experience with the path module, worst case scenario you'd end up with a bunch of ../../.. relative path directives.

Say I have app running with configuration like this:

bristol.addTarget('console').withLowestSeverity('info').withFormatter('human')

and would like to make logging more verbose by switching to debug without restarting an app (e.g. I'm having issues and would like to track them down with more logs).

I don't see a way to get this working, is this possible?

Hi all, how can I use splunk with Bristol? According to https://www.reddit.com/r/node/comments/26mf7e/winston_logging_replacementalternative/ it should be possible, or not :-) ?

For certain messages, it's not interesting where they originate from (file:line). One example would be startup messages:

logger.info("We're up and running");  // the filepath:line is not interesting

Fortunately, though this is undocumented, .addTransform also receives the file:line as an object. I've tried adding a transform to suppress the line, but if it returns the empty string, the file:line is still output:

import logger from 'bristol';
logger.addTarget('console').withFormatter('human');

logger.addTransform(e => e.file && e.line ? '' : e);

logger.info('Started!');  // [2018-07-12 16:19:36] INFO: Started (file:///...:6)

Returning a whitespace is better, though because the file:path object is the first passed on to transform functions, this will lead to an extra whitespace in the middle of your output:

logger.addTransform(e => e.file && e.line ? ' ' : e);

logger.info('Note double space');  // [2018-07-12 16:28:35] INFO:   Note double space

I have a very strange issue where a module is producing a prototype-less (null) object, which causes Bristol to blow up when the object gets run through the internal forEachObj() function.

I'm honestly not sure if this should be addressed by Bristol, but it would be nice to never have Bristol throw an error (which has been the case up to now).

Here's the code to reproduce the issue:

function forEachObj(obj, cb) {
    var brakesOn = false,
        brake = function() { brakesOn = true; };
    for (var key in obj) {
        if (obj.hasOwnProperty(key))
            cb(key, obj[key], brake);
        if (brakesOn) break;
    }
}

let badObj = {value: 5};
badObj.__proto__ = null; // set null proto

forEachObj(badObj, function() {})
// TypeError: obj.hasOwnProperty is not a function

Any thoughts are appreciated.

Hi @TomFrost and contributors,

Would you be open to moving including the formatters included with the module the top level export ? One example for the reasoning behind this request:

The json formatter is almost 100% what I want for everything, but I'd like to add static properties to a particular target ( not globally ). To achieve that, I can modify the function arguments before invoking the standard json function.

I currently can do this just by just reaching into the module ( require('bristol/lib/formatters/json') ) but its brittle because you can change that path an any time 😄

Thanks for the module 👍

Bristol 1.0

The 1.0 release of Bristol is in the works, and will be a major breaking release with a focus on performance, flexibility, and configurability.

Shortcomings of 0.x

• One of the most important features of Bristol is the separation of formatter and target. This is wildly useful but not found in any other major logging library. However, some targets require control of their own formatting, and it's a common practice right now to use the JSON formatter and then call JSON.parse in the custom target to get access to the pure object data again. This is bad. See #56.
• The configuration method written for Bristol was created at a time that chained methods were extremely popular. In modern times of 12-factor code and env var-based configuration, this is annoying and requires users to write significant code to translate traditional config by json or env vars into chained method calls. See #31, #32, #33.
• Items that should be configurable, such as whether file/line number data is included, are not. See #53.
• Very little consideration was put into the performance of the console logger, as logging to file was the gold standard when Bristol was written. In modern applications, logging to stdout is the standard, and console.log is a blocking operation.
• Bristol has a number of features such as global static and dynamic variables, field transforms, etc., that are useful, but underutilized and inconsistent.
• Bristol has incredibly fine-grained target content restrictions that, while nice, haven't been used by almost anyone I've talked to. Bristol should default to being lean and minimal, and these features can be added back only if users present a good consistent use case for them
• It's a growing trend to have some "global" variables follow threads of operation, such as the logs generated by a single user's request, but shouldn't be global to the target. The ways users handle this -- creating a new Bristol instance per-request, exposing a "facade" log method, or maintaining a set of data that has to be manually passed to every log call -- are cumbersome and sometimes perform poorly. See #46.

Solutions in 1.0

• Like Cryptex, Bristol will be able to be fully configured through a set of environment variables when it's instantiated without any other configuration. A config object can be passed to the constructor as well if environment variables aren't ideal. The chained configuration will be going away for Bristol in general as well as for new targets post-instantiation.
• Bristol 1.0 will keep the concept of formatters and targets, but targets will be supplied both the formatted string as well as the original raw data object. Target plugins have an ethical responsibility to respect the formatted string if it's present, and if possible to do so.
• 1.0 will eliminate static and dynamic global variables, as well as transforms. All manipulations to be performed on log events between the time of the log call and the time they're written to the target will be handled by middleware, similar to express.js. Middleware will be functions with the signature fn({Object} logData, {Object} options = {}), where logData will contain the timestamp, severity, and any other data that Bristol attaches to log messages internally. Options can be specified when the middleware is attached. Middleware must operate synchronously (so that messages write to the target in order) and make their changes directly to the logData object.
• Middleware can be attached directly to the Bristol instance (affecting all targets) or to specific targets.
• Bristol instances can be "forked", producing an instance that one can attach middleware to without affecting the parent instance. Use case: For each new request to your API, fork your logger and run this line: logFork.use(logData => { logData.user = req.tokenData.user }). Pass your fork along to your request handler and now everything you log for that specific request gets tagged with the user that generated it. The fork will be garbage collected when the request is handled.
• Formatters are just middleware that return a string and run after all the other middleware.
• The excluding and onlyIncluding target configs will be removed, barring rampant complaints. No one restricts by anything but severities in real-world use cases.
• Assuming console.log is not ideal for prod loads as I suspect, I'd keep a console.log logger for dev where blocking is useful, but add a stdout logger for non-development environments.

Limiting scope

1.0 will be a breaking update, and I'd like to define its scope by changing only the things, like the above, that are either breaking changes or features that users absolutely must learn about (such as using a stdout target instead of console target). While we could all list gobs of additional features we want on top of 1.0, I'd prefer to keep the 1.0 project small and iterate through the non-breaking changes later.

I also intend for 1.0 to draw a firm line in what Bristol ships with by default. Targets that are generalized or universal to most users will be included in Bristol -- file, console, stdout for sure in 1.0, syslog makes sense, I could even see an argument for a generic HTTP target that POSTs JSON logs to a configured URL with configured headers. Targets that are specific to aggregator products or narrow platforms will be excluded from Bristol core (Loggly has already been removed from master, for example), but the readme will encourage folks to publish middleware and targets to npm with the prefix bristol-.

RFC?

Paging @MarkHerhold @Fluidbyte @jeffijoe @dandv for your thoughts, as each of you have communicated challenging use cases that I'm hoping to largely solve with the above. I already know it solves my own ;-).

I'm trying to build a target for a cloud logging system (Rollbar) that accepts object parameters in its log calls, and parses that object and displays individual keys in the web UI. A sample log call would be:

logger.info('apples vs. oranges', { apples: foo, oranges: bar });

Problem is that the target function receives the message already formatted as string. Sending that raw string to the logging service is a no-go. In order to reconstruct my original object, I have to JSON.parse() the message argument. This is slow and roundabout.

I also need to scrub the severity and message fields from the object, because they're already included in the call itself.

It would be great if Bristol made available the original message arugment(s), perhaps as rest parameters to the target function.

In the meantime, here's the code I'm using:

function rollbarLogger(options, severity, date, messageAlreadyFormatted) {
  const mafObject = JSON.parse(messageAlreadyFormatted);
  const message = mafObject.message;
  delete mafObject.message;
  delete mafObject.severity;
  rollbar[severity](message, mafObject);
}

Let's say you have multiple processes logging to the same file:

var cluster = require("cluster");
var log = require("bristol");

var num_cpus = 2;

if (cluster.isMaster) {
    for (var i = 0; i < num_cpus; i++) {
        cluster.fork();
    }

} else {
    log.addTarget("file", { file: "log.txt" });
    log.addTarget("console")
        .withFormatter("human")
        ;
    log.info(process.pid, "Lorem Ipsum");

}

Then run the script, and while the script is running, fire up lsof:

$ lsof ./log.txt 
COMMAND   PID USER   FD   TYPE DEVICE SIZE/OFF     NODE NAME
node    49511 doug   13w   REG    1,2      788 66444792 ./log.txt
node    49512 doug   13w   REG    1,2      788 66444792 ./log.txt

Two processes, two different file descriptors, same file. Under UNIX, there is no guarantee that writes to a file are atomic, thus running the risk of partial lines being written to one file descriptor before the next line is written, thus creating a "staircase" effect.

Opening files in the master process then spawning the child process won't help. (I tried)

The best solution I found so far is to have a single process write files. This can be done with process.send() as follows:

//
// In the master process
//
process.on('message', function(m) {
   // Write to file
});

//
// In the child process, JSON data structure is sent to the master process
//
process.send({ foo: 'bar' });

There are probably other ways to accomplish the same. This particular technique worked for me in my projects.

Hi @TomFrost,

Just wanted to check if you still have plans to maintain this package. I'm an OSS developer myself and have my fair share of packages I had to abandon. Those who consider Bristol vs. alternatives might want to take the maintenance status into consideration.

Thanks!

I suspect that when logrotate creates a new empty file (with logrotate.conf option create), the writeable stream is gone.

Once the app is restarted, new logs can be written again.

Working around this issue by using logrotate.conf option nocreate has the same problem. The file is not re-created by Bristol.

I don't see any error messages.

Moment should be updated to at least 2.11.2.

https://nodesecurity.io/advisories/55

When logging an object with the human formatter, I see that the output is different in nested object keys and values, vs. root ones:

• keys are quoted in nested objects, and not quoted in the root
• string are not quoted if they're values of root fields
• empty arrays are not logged if they're values of root fields

import log from 'bristol';
log.addTarget('console').withFormatter('human');

const object = {
  rootString: 'key name not quoted, string should be quoted',
  nested: {
    string: 'string is quoted, and so is the key',
    array: [],  // empty array correctly logged
  },
  array: [],  // nothing logged
};

log.info('Unquoted strings', object);

Output:

[2019-05-26 00:30:47] INFO: Inconsistent output (file:///.../bristol.mjs:13)
	rootString: key name not quoted, string should be quoted
	nested: 
	    {
	        "string": "string is quoted, and so is the key",
	        "array": []
	    }
	array: 

const logger = new Bristol()
logger.addTarget(function() {}).withFormatter(function() {
  console.log(arguments[3])
})
logger.error('hey ho', { here: 'we go' }, 123, new Date())

This is what I see in the console:

    [ 'hey ho',
      123,
      { file: '/Users/jeff/Projects/bristol-stackdriver/src/__tests__/index.test.ts',
        line: '20',
        here: 'we go' } ]

Am I missing something? 😄

Can you make a types/@bristol pull request or add a index.d.ts file to the repo and do an npm release please?

I have this I believe:

interface LogError {
  message?: string,
  reason?: any,
  stack?: any
}

interface LogData {
  code?: number,
  id?: string,
  path?: string,
  error?: LogError,
  data?: any
}

declare module 'bristol' {
  function addTarget(target: any, opts?: any) : any
  function withFormatter(formatter: string) : any
  function withLowestSeverity(severity: string): any
  function info(message: string, data: LogData) : any
  function warn(message: string, data: LogData) : any
  function error(message: string, data: LogData) : any
}

import logger from 'bristol';
logger.addTarget('console');
logger.addTarget('file', {
  file: 'bristol.log',
});

logger.info('Not logged to the file');
process.exit(1);

Winston has the same issue.

Hi,

I've just ran a vulnerability scan on my app and got a known vulnerability for moment.js in 2.5.1:

https://nodesecurity.io/advisories/55

As moment didn't have any breaking changes, I'd propose to update moment dependency to latest 2.22.1.

Cheers
Marcel

I'm writing a custom formatter that requires logUtils.

However, the latest version of bristol on npm ^0.3.3 does not appear to include the commit from 16th December that made logUtils public: -

cacb279

If I run:

npm install bristol --save

Local package.json reports:

"dependencies": {
"bristol": "^0.3.3",
...
},

but node_modules\bristol\bristol.js is missing the changes.

see line 364 & 356:
module.exports = new Bristol();
module.exports.Bristol = Bristol;

It's missing the last 2 lines:

module.exports._logUtil = logUtil
module.exports.Bristol.logUtil = logUtil

The source on github is correct, so is it npm that is holding an older version?

Thanks for looking. Love bristol logging btw :)

Loving Bristol, and have even written a target + formatter myself. 😄

It would be awesome to have support for child loggers! Imagine creating a child logger for each HTTP request, then set some globals for it (such as the calling user, request info, etc). It would share the transports, formatters and globals of it's parent.

Example API:

const logger = new Bristol({ ... })

app.use(authenticate())
app.use((ctx, next) => {
  const child = logger.createChildLogger({ /*additional config for child */ })

  child.setGlobal('user_id', () => ctx.state.user.id)
  ctx.logger = child
  return next()
})

app.use(get('/todos', (ctx) => {
  ctx.logger.info('Getting todos')
}))

I created a wrapper for the logger because I did not want to use a global:

var express = require('express');
var app = express();
var log = require('bristol');
var debugMode = app.get('env') == 'development';

// Bristol provides error, warn, info, debug, and trace severity levels

if ( debugMode ) {
    log.addTarget('console')
        .withFormatter('human');

    log.addTarget('file', {file: '/logs/debug.log'})
        .withLowestSeverity('debug')
        .withHighestSeverity('debug')
        .withFormatter('human');
}

// Always log errors
log.addTarget('file', {file: '/logs/error.log'})
    .withLowestSeverity('warn')
    .withHighestSeverity('error')
    .withFormatter('commonInfoModel');

module.exports = log;

In my router index.js, I wanted to get the log and set a global with the function name

var log = require('../lib/log.js');
log.addGlobal('function', "router.post('/my/router/path')");

However, I get a TypeError

TypeError: Object #<Bristol> has no method 'addGlobal'
    at renderView (/Users/promise/WebstormProjects/demo/routes/index.js:7:9)
    at Object.router.get.renderView.title [as handle] (/Users/promise/WebstormProjects/demo/routes/index.js:34:5)
    at next_layer (/Users/promise/WebstormProjects/demo/node_modules/express/lib/router/route.js:103:13)
    at Route.dispatch (/Users/promise/WebstormProjects/demo/node_modules/express/lib/router/route.js:107:5)
    at proto.handle.c (/Users/promise/WebstormProjects/demo/node_modules/express/lib/router/index.js:205:24)
    at Function.proto.process_params (/Users/promise/WebstormProjects/demo/node_modules/express/lib/router/index.js:269:12)
    at next (/Users/promise/WebstormProjects/demo/node_modules/express/lib/router/index.js:199:19)
    at Function.proto.handle (/Users/promise/WebstormProjects/demo/node_modules/express/lib/router/index.js:151:3)
    at Layer.router (/Users/promise/WebstormProjects/demo/node_modules/express/lib/router/index.js:24:12)
    at trim_prefix (/Users/promise/WebstormProjects/demo/node_modules/express/lib/router/index.js:240:15)

I do not believe it has anything to do with my wrapper as I get the same error with

var log = require('bristol');
log.addGlobal('function', "myFunction()");

Is it possible to add/support the use of colors with a human readable console target, similar to how npm logs colors? I find it significantly helps with ease of quickly parsing log output.

Luxon is a good one.

I'm asking a question because I can't find any resources that speak directly to the question. I apologize for opening an issue when I don't have an actual problem. (Feel free to close this issue whenever.)

I'm using Bristol in a node app where I'm also using cluster. Because of the nature of cluster, logging has potential issues associated with it. Specifically, when a child process logs an error or event there is no way to tell what state the child process is in compared to the master process, and logs get confusing when they come out with two associated lines interspersed with others from different processes.

That leaves two options: log the event/error directly from the child process or send a message to the master then log from there.

It seems logical to me to log errors that would result in a process termination directly from the child, while sending any other important notifications to the master to log (along with a processID for the child). This has some obvious performance penalties associated with it, so I'd assume any debug logs would have to be logged directly from the child processes also.

My questions:

1. Is there a set of best practices associated with this issue that you know of?
2. Does Bristol do anything to change the way the stdout and stderr from cluster are piped? (I know of at least one other logging library that does intentionally change this behavior.)

Thanks!

Jared

PS: Bristol is awesome and incredibly helpful. Keep up the good work. By contrast, Winston and Bunyan are both swimming in un-handled issues and seem over-complicated and poorly maintained. I really appreciate that you've put in the time and effort to create this library.

The origin logging always outputs the same file and line making it effectively useless. Every logged line shows the origin as coming from Bristol.js.

My application is running Node 6.6.0 with ES6 features.

2016-09-22 11:35:25 message="up and running!" severity="info" file="/.../node_modules/bristol/lib/Bristol.js" line="140"