IBM/node-sdk-core

Bug in DEBUG ?

huineng opened this issue ยท 5 comments

when i add my process.env.DEBUG variable to "ibm-cloud-sdk-core:info" i not only get the info items i also get an ERROR log , while this is not an error

"@ibm-cloud/cloudant": "^0.0.21",
"typescript": "^4.5.2",
"webpack": "^5.64.3",

node v16.13.0

  ibm-cloud-sdk-core:info Credential file does not exist. Will not be used +0ms
  ibm-cloud-sdk-core:info Credential file does not exist. Will not be used +2ms
  ibm-cloud-sdk-core:info Credential file does not exist. Will not be used +3ms
  ibm-cloud-sdk-core:error {
  ibm-cloud-sdk-core:error   status: 200,
  ibm-cloud-sdk-core:error   statusText: 'OK',
  ibm-cloud-sdk-core:error   headers: {
  ibm-cloud-sdk-core:error     'cache-control': 'must-revalidate',
  ibm-cloud-sdk-core:error     connection: 'close',
  ibm-cloud-sdk-core:error     'content-length': '208',
  ibm-cloud-sdk-core:error     'content-type': 'application/json',
  ibm-cloud-sdk-core:error     date: 'Wed, 24 Nov 2021 20:29:36 GMT',
  ibm-cloud-sdk-core:error     server: 'CouchDB/2.3.1 (Erlang OTP/19)',
  ibm-cloud-sdk-core:error     'x-couch-request-id': 'a94debd32c',
  ibm-cloud-sdk-core:error     'x-couchdb-body-time': '0'
  ibm-cloud-sdk-core:error   },
....
ibm-cloud-sdk-core:error   data: {
  ibm-cloud-sdk-core:error     couchdb: 'Welcome',
  ibm-cloud-sdk-core:error     version: '2.3.1',
  ibm-cloud-sdk-core:error     git_sha: 'c298091a4',
  ibm-cloud-sdk-core:error     uuid: '3fd2dc04a0c4b62f04ff84157d3bca8d',
  ibm-cloud-sdk-core:error     features: [ 'pluggable-storage-engines', 'scheduler' ],
  ibm-cloud-sdk-core:error     vendor: { name: 'The Apache Software Foundation' }
  ibm-cloud-sdk-core:error   }
  ibm-cloud-sdk-core:error } +0ms
$cloudant (constructor): Initialisation done - {"couchdb":"Welcome","version":"2.3.1","git_sha":"c298091a4","uuid":"3fd2dc04a0c4b62f04ff84157d3bca8d","features":["pluggable-storage-engines","scheduler"],"vendor":{"name":"The Apache Software Foundation"}}

thanks

The inclusion of error level logging is expected when enabling info - because it gives info and below, but agreed this shouldn't be logging a 200 response at error level.

I'm going to transfer this issue to node-sdk-core which is where the logging code is.

I believe this was caused by JSON.stringify failing on the response e.g.

logger.debug(JSON.stringify(response, null, 2));
(if the stringify fails it switches from debug to error). Although it is not clear what the underlying reason for the stringify failure is I've certainly seen axios responses fail to stringify because of circular structures before and a number of potential causes and workarounds for that are discussed in axios/axios#836.

For the core folks perhaps util.inspect would be a better alternative to JSON.stringify for the debug logging?

Rather than use util.inspect(), it turns out that the logger's debug() and error() functions will pretty-print the passed-in object (request or response object) just fine so I was able to simply remove the JSON.stringify() calls altogether.

๐ŸŽ‰ This issue has been resolved in version 2.17.8 ๐ŸŽ‰

The release is available on:

Your semantic-release bot ๐Ÿ“ฆ๐Ÿš€

Since this was originaly reported against cloudant-node-sdk I should mention FTR that we included the fixed 2.17.8 in our 0.0.24 release.