Logging response object from request() results in process hang

[robertdimarco]

Using Node v0.10.38 w/ Winston v1.0.0, the following code will cause the process to spike to 100% CPU and hang:

var request = require('request');
var winston = require('winston');

request
  .get('https://cdnjs.cloudflare.com/ajax/libs/jquery/2.1.3/jquery.min.js')
  .on('response', function(resp) {
    console.log('a');
    winston.error('logging error', resp);
    console.log('b'); // we'll never get here
  });

Expected Output:

a
<lots of data here>
b

Actual Output:

a

Notes:

Interestingly, if you replace the above endpoint with an non-SSL, i.e. http:// URI, the object is logged fine. Also note that the above script works successfully in Node v0.12 and io.js.

[indexzero]

Probably has to do with serialization of some crypto object types. We will investigate.

[ebourmalo]

I get the same behaviour with the current version of Winston and got my app in production to hang indefinitely :( I will shoot a fix very soon

[ebourmalo]

When logging the response object, what actually happens is the following:

• the response object is defined in the meta data to log
• as specified in the documentation, util.inspect (node core api) is used to log these meta data
• If no depth param is given in the logger options, util.inspect will try to recursively browse the whole object, no matter how deep it goes. Unfortunately, it will be an infinite loop if this object has circular dependencies (it seems to be the case of the response object in express).

I ended up:

• setting the depth param in my logger configuration to avoid future hang due to complex circular objects

  return winston.loggers.get(moduleName, {
    console: {
      colorize: true,
      depth: 5,
      label: moduleName,
      handleExceptions: true,
      humanReadableUnhandledException: true,
      prettyPrint: true,
    },
  });

• make a purify function in my specific case to keep only things I care about in the http response object.

Hope this helps :)

[James-Firth]

I was using unirest (which uses request) and had the same issue as @robertdimarco when attempting to log via
winstonLoggerObject.verbose('test response %j', response) in the end callback.

EDIT: @ebourmalo thanks for the tip I can use as a hotfix :)
Setting depth doesn't seem to fix the issue in unirest/request's response object.

[mattleong]

Hi all,

I'm attempting to use node-fetch with winston and I'm running into this issue. Is there any update on a resolution?