Debug through logger's debug function

[bragma]

Pardon me if this has already been answered. I know "debug" is not a logger and I respect that. I do not want to log with debug, I'd like debug to output in my logs instead. :-)
Specifically I'd like all third party modules using the ubiquitous "debug" to log through Winston's debug function. It's a matter of consistency turning log levels on/off dynamically.
Is it possible?

I've tried to leverage node's module caching in this way:

var Debug = require('debug');
var Logger = require('winston');
Debug.log = Logger.debug;

var mod = require('module_using_debug');

It's not working... :-(

[stephenmathieson]

hmm.. a super primitive example works for me:

// deps
var winston = require('winston')
var Debug = require('debug');
Debug.log = winstonWrapper;
var debug = Debug('myapp');

// create your winstonn logger.. whatever
var logger = new winston.Logger({
  transports: [
    new winston.transports.Console({ raw: true })
  ]
})

// debug some stuff
debug('hello world')
setInterval(work, 250);

var n = 0;
// do work
function work() {
  debug('doing work (%d)', ++n)
}

// the magic happens here
function winstonWrapper() {
  logger.log.apply(logger, ['info'].concat(arguments));
}

yields:

$ DEBUG=* DEBUG_COLORS=0 node winston-example.js
{"level":"info","message":"{ '0': 'Tue, 08 Dec 2015 17:51:15 GMT myapp hello world' }"}
{"level":"info","message":"{ '0': 'Tue, 08 Dec 2015 17:51:15 GMT myapp doing work (%d)',\n  '1': 1 }"}
{"level":"info","message":"{ '0': 'Tue, 08 Dec 2015 17:51:15 GMT myapp doing work (%d)',\n  '1': 2 }"}
{"level":"info","message":"{ '0': 'Tue, 08 Dec 2015 17:51:15 GMT myapp doing work (%d)',\n  '1': 3 }"}
{"level":"info","message":"{ '0': 'Tue, 08 Dec 2015 17:51:16 GMT myapp doing work (%d)',\n  '1': 4 }"}
{"level":"info","message":"{ '0': 'Tue, 08 Dec 2015 17:51:16 GMT myapp doing work (%d)',\n  '1': 5 }"}
{"level":"info","message":"{ '0': 'Tue, 08 Dec 2015 17:51:16 GMT myapp doing work (%d)',\n  '1': 6 }"}
^C

you may be running into versioning issues with module_using_debug though...

[bragma]

Thanks, it seems to be working. I was misleaded by some unexpected output. Now I am looking for a way to turn off debug's timestamp, since my logger already timestamps lines.
Btw, I think there is no need for the wrapper, a "bind" is enough:

Debug.log = Winston.debug.bind(Winston);

[bragma]

Answering to myself: just need to replace debug's formatArgs function...

[gustavomick]

besides implementation ( and because i was thinking to use same technique ) .. is these a right approach? binding/composing debug through winston i mean. thanks

[bragma]

After using it for a while, I'd say it's not a perfect solution. It has at least 2 problems:

1. Due to the way caching works, you have no guarantee that 3rd party modules will use the winston/debug instance you configured. If they don't, the solution won't work. Since even a minor version change is a different instance of a module, it does not work very often.
2. For this solution to work, you have to enable all debug messages, then rely on Winston to disable/enable logging. This for sure has an overhead, since debug does not know about this "trick" and will format and emit all messages, Winston has to do some processing on them and finally ignore them. Considering that debug is often used for tracing code, it may be a lot of messages being uselessly processed and then thrown away.

[thebigredgeek]

@bragma @stephenmathieson middleware should solve this: #370

[thebigredgeek]

^Feel free to join in on convo

[rbriank]

Did this happen? Having trouble finding it anywhere in the docs for 3.1