Stack traces are logged in a single line

jarnor · January 22, 2021, 9:39am

Hi!

First of all, I must say thank you all contributors for your awesome work with Parse. We’ve used it in production since parse.com shut down and it’s comforting to see that it’s still under active development

We’ve been quite a few releases behind since the 3.0 upgrade was quite extensive for us (we have >500 cloud functions). So when I tried to upgrade beyond 3.3 I realized that stack traces are logged in a single line, both for stdout when running locally and in our production environment as well (Heroku -> Papertrail)

It seems to have been introduced when Winston was upgraded to v3 for Parse 3.3 (Winston 3 upgrade by stage88 · Pull Request #5496 · parse-community/parse-server · GitHub)

This is an error that is thrown in the beforeSave on version 3.1.3 (I’ve simplified the output for clarity).

error: beforeSave failed for SomeClass for user undefined:
  Input: {...}
  Error: {"message":"Some error message","code":141} className=Notification, triggerType=beforeSave, message=Some error message, code=141, user=undefined
error: Some error message message=Some error message, stack=Error: Some error message
    at error (/node_modules/parse-server/lib/triggers.js:300:16)
    at wrapped (/node_modules/newrelic/lib/transaction/tracer/index.js:184:28)
    at Promise.linkTransaction (/node_modules/newrelic/lib/instrumentation/promise.js:295:65)

And here is the log output for the same error on version 3.10.0. The behaviour seems to be the same in version 4.5.0.

error: beforeSave failed for SomeClass for user undefined:
  Input: {...}
  Error: {"message":"Some error message","code":141} {"className":"Notification","triggerType":"beforeSave","error":{"message":"Some error message","code":141}}
error: Parse error: Some error message {"code":141,"stack":"Error: Some error message\n    at error (/node_modules/parse-server/lib/triggers.js:345:16)\n    at wrapped (/node_modules/newrelic/lib/transaction/tracer/index.js:184:28)\n    at Promise.linkTransaction (/node_modules/newrelic/lib/instrumentation/promise.js:295:65)"}

Is this an issue anyone else have experienced? Any help would be much appreciated!

Best,
Johan

jarnor · February 3, 2021, 6:28pm

Hi again! Just checking if someone else have found a workaround for this, like consuming the logs with any specific tool/service.

Or maybe you don’t get errors in your applications

dplewis · February 4, 2021, 12:49am

@jarnor I did a fix for winston interpolation a few weeks ago. I don’t know if that fixes the issue you are having. (not released yet)

github.com/parse-community/parse-server

fix(Logger): Handle interpolating stdout

parse-community:master ← parse-community:winston-console

opened 08:36PM - 07 Jan 21 UTC

dplewis

+14 -2

### New Pull Request Checklist  - [ ] I am not disclosing a [vulnerability](https://github.com/parse-community/parse-server/blob/master/SECURITY.md). - [ ] I am creating this PR in reference to an [issue](https://github.com/parse-community/parse-server/issues?q=is%3Aissue). ### Issue Description When running VERBOSE=1, you will see this if you are doing Live Queries verbose: Subscribe messsage %j verbose: testafterSave is triggered verbose: ClassName: %s | ObjectId: %s verbose: Current client number : %d verbose: Request: %j verbose: Push Response : %j ### Approach From [winston's doc](https://github.com/winstonjs/winston#string-interpolation): > The log method provides the string interpolation using util.format. It must be enabled using format.splat(). This PR correctly pipes interpolation into the console transport. ### TODOs before merging  - [x] Add test cases - [x] Add entry to changelog - [ ] Add changes to documentation (guides, repository pages, in-code descriptions) - [ ] Add [security check](https://github.com/parse-community/parse-server/blob/master/CONTRIBUTING.md#security-checks) - [ ] Add new Parse Error codes to Parse JS SDK - [ ] ...

jarnor · February 9, 2021, 3:15pm

Many thanks for your reply @dplewis. I tried your fix (changed to "parse-server": "https://github.com/parse-community/parse-server", in package.json), but the issue still remains.

I guess I can implement my own logger via the loggerAdapter API, or should I try to fix it in a PR? I’m not sure if the new format is a bug or a feature.

dplewis · February 11, 2021, 2:01am

Feel free to open a PR! We are more than welcome to help

jarnor · February 11, 2021, 9:26am

I think this is related to this issue in winston https://github.com/winstonjs/winston/issues/1338. There seems to be several examples of how to log the stack correctly (for stdout), but since we’re still using winston 2 and need to upgrade our Parse version I think I’ll go ahead and just implement our own logger adapter for now.