newrelic / node-newrelic

New Relic Node.js agent code base. Developers are welcome to create pull requests here, please see our contributing guidelines. For New Relic technical support, please go to http://support.newrelic.com.
Apache License 2.0
969 stars 398 forks source link

Unhandled error during JSON.parse #1744

Closed OlenaHryshko closed 1 year ago

OlenaHryshko commented 1 year ago

Description

Using newrelic to capture application logs + pino as a logger agent. While logging using pino, it is possible to pass mergingObject to add more context to the log. In case key(s) of the mergingObject contains " symbol, it is not getting shielded. So, logged object is not a JSON string, but newrelic lib tries to parse it to a JSON object.

NewRelic throws an error below:

SyntaxError:   Unexpected token s in JSON at position 219
at JSON.parse (<anonymous>)
at formatLogLine   (/app/node_modules/newrelic/lib/instrumentation/pino/pino.js:128:31)
at /app/node_modules/newrelic/lib/aggregators/log-aggregator.js:46:16
at Array.map (<anonymous>)
at LogAggregator._toPayloadSync   (/app/node_modules/newrelic/lib/aggregators/log-aggregator.js:44:32)
at LogAggregator.send   (/app/node_modules/newrelic/lib/aggregators/base-aggregator.js:105:32)
at /app/node_modules/newrelic/lib/agent.js:396:18
at new Promise (<anonymous>)
at Agent.forceHarvestAll   (/app/node_modules/newrelic/lib/agent.js:392:29)
at Timeout.afterTimeout [as _onTimeout]   (/app/node_modules/newrelic/lib/agent.js:514:11)

Expected Behavior

Handle JSON.parse error. In case it is not possible to parse JSON object from log string, save the whole log string as a message.

Troubleshooting or NR Diag results

As per comment in the code, newrelic calls pino asJson method. It returns invalid JSON string, which is getting passed into newrelic reformatLogLine method. image image

Steps to Reproduce

  1. Setup newrelic and enable logging.
  2. Setup pino.
  3. Get instance of pino logger and call logger.info({'some"prop': {'details': true}}). Code snippet:
    
    const pino = require('pino');
    const logger = pino();

logger.info({'some"prop': {'details': true}});


This will result in the log below:
`{"level":30,"time":1690897379299,"pid":41644,"hostname":"your-hostname","some"prop":{"details":true}}`
After this newrelic will pick up the log, try to do JSON.parse and throw the error mentioned above.

## Your Environment

* Node version: 16.16.0
* pino package version: 7.11.0
* newrelic package version: 9.14.1 (checked latest one 10.6.0 - same code algorithm)

## Additional context
workato-integration[bot] commented 1 year ago

https://issues.newrelic.com/browse/NR-147361

bizob2828 commented 1 year ago

@OlenaHryshko thanks for your report. We can provide some defensive code but this also appears to be a bug with pino because it cannot properly stringify an object that has a " in a key. Since pino manually builds serialization/de-serialization. If you do this in Node.js it just works

> JSON.stringify({ 'test"me': 'value'})
'{"test\\"me":"value"}'
> const a = JSON.stringify({ 'test"me': 'value'})
undefined
> JSON.parse(a)
{ 'test"me': 'value' }
>
OlenaHryshko commented 1 year ago

@bizob2828 thanks for your response. Created an issue in pino lib. We'll see if it's possible to fix it there. As soon as this serializer is custom, I'd suggest adding some defensive code in any case. You never know what edge cases might occur.

bizob2828 commented 1 year ago

@OlenaHryshko that has been released in 10.6.2

OlenaHryshko commented 1 year ago

@bizob2828 thank you for the notification