12

Preamble

A known library Winston has the same issue as many other different libraries that serve the purpose of multi-transport logging. When one of the transports is console the reported message in debugger console (browser or any environment for Node.js) misses very powerful information: the place where the initial call was initiated (developer's file) and instead the place of call inside the library is displayed. In this case multiple calls from different files/places are all reported as if logged from one same place.

Solutions tried

I've research two approaches. One was trick on browser/Node when they infer the place of call to console.log. The only way i found it can be done is via source maps. This is a technology that allows to map minified js sources to original sources and debug it while looking at the full source. However, this assumes that there is one transition from real (minified) source to original. And in case of substituting source for console.log in potential library mylogger should be dynamic and reflect the multiple places where mylogger.log is called. I haven't found a way to do this dynamically since browser loads the map file just once.

Another one was to substitute the call of console.log and inside of custom function call all other transports (this can be the same Winston). However, if we do a simple replace like below

var originalLog = console.log;
console.__proto__.log = function(message){
    message = [new Date().toISOString(), message].join(' ');
    originalLog.call(console, message);
//here send via other transports
    body.innerHTML = body.innerHTML + message + '<br/>';
};

the place of call to originalLog will always be the same and it will be reported accordingly in console output. So I thought of intercepting the call to console.log but leaving the original native function in place. But I failed to get the parameters of call.

function interceptGettingLog(){
    var originalLog = console.log;
    Object.defineProperties(console.__proto__, {
        log: {
            get: function(){
//arguments is always empty here, which is not a big surprise
                originalLog.call(console, 'log accessed ' + JSON.stringify(arguments));
                return originalLog;
            }
        }
    });
}

Question in short

Does anybody know a different approach to logging or a way to trick on browser/Node.js when calling console.log? The goal is to have a multi-level multi-transport logger which would allow to switch verbosity and transports in configuration (which will be different for development and production), have full power of console.log and at the same time neat syntax, i.e. a single function call at a place where developer needs to log something. Thanks for reading :)

Kirill Slatin
  • 6,085
  • 3
  • 18
  • 38

2 Answers2

1

So far this is the best solution I could make up. I assume it to be not clean as it forces specific syntax on the calling line. But it works.

function logInfo(){
//do multitransport multilevel logging on your decision
// for example, Winston
    var args = Array.prototype.slice.call(arguments);
    winston.log.apply(winston, args);
    if(levels.contains('console')){
//return a console.log function to call it in the 'right' place
        return console.log.bind.apply(console.log, [console].concat(args));
    }else{
//return a no-operation function to skip output to console
         return function nop(){};
    }
}

Usage

...
logInfo('My message:', {foo:true, count: 100})();
...

The trick is to return console.log bound with arguments passed to the main logging function and call it in the same place where the main logging function is called. This way we avoid duplication of code: parameters to log a specified only once. Brackets () after the main logging function indicate whether there will be output to console. In case configuration dictates NOT to output to console we return an empty function.

PS I would consider clean the one that substitutes console.log. So you can apply the patch without modifying existing code with console.log calls. But it is impossible to achieve that without overloading (), which is not doable in ES5.

Credit for bind called with array of arguments goes to @FelixKling https://stackoverflow.com/a/21507470/4573999

Community
  • 1
  • 1
Kirill Slatin
  • 6,085
  • 3
  • 18
  • 38
1

In Chrome dev tools, you can 'blackbox' the wrapper script and chrome will report the point where the function within the blackboxed script is called.

You right click the source script in dev tools sources and select 'Blackbox script'.

Chrome dev tools notes on blackboxing

Paul Irish wrote a gist about it

dannyshaw
  • 368
  • 2
  • 6
  • I would call this a canonical answer. Thanks. Although can't stand pointing out some drawbacks of this solution: 1. This seems to be working in Chrome only (unfortunately blackboxing in FF doesn't have this effect); 2. when in production/stage site all scripts are combined into one, you can't really blackbox the log-helper.js. In case of .`console.error` you can still easily find the place of interest (because of printed stacktrace), but with `console.log` this will be difficult – Kirill Slatin May 06 '15 at 01:52
  • Yeah it's a workaround. It might work if you also output source maps in production. But to be honest, depending on console.log in production might not be the best idea in itself. – dannyshaw May 06 '15 at 08:49