graphql-js icon indicating copy to clipboard operation
graphql-js copied to clipboard

GraphQL Stack Traces are (Needlessly) Unhelpful;

Open machineghost opened this issue 4 years ago • 7 comments

Here is a stack trace I recently got:

 Error: Cannot return null for non-nullable field User.id.
    at completeValue (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:560:13)
    at completeValueCatchingError (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:495:19)
    at resolveField (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:435:10)
    at executeFields (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:275:18)
    at collectAndExecuteSubfields (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:713:10)
    at completeObjectValue (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:703:10)
    at completeValue (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:591:12)
    at completeValueCatchingError (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:495:19)
    at resolveField (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:435:10)
    at executeFields (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:275:18)
    at collectAndExecuteSubfields (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:713:10)
    at completeObjectValue (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:703:10)
    at completeValue (/home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:591:12)
    at /home/me/projects/my-project/server/node_modules/graphql/execution/execute.js:492:16

The problem is, it's entirely made up of lines from graphql, which means it's entirely worthless for helping me understand where the error occurred (ie. the entire thing stack traces are supposed to do). All I know is that it involved a resolver which somehow involved a User ID.

I don't mean to sound ungrateful for awesome free software (that is the best way to build an API today) ... and I very much am appreciative of all the hard work that has gone into this project ... but would it kill you to at least include the query and variables used in the stack trace?

At the moment it really feels like the library is saying "Oh you messed up? Well, too bad: you're on your own now chump! That's you what you get for making a mistake." ;) But surely you want to help users understand errors, no? And surely GraphQL has the query/variables available to include in the error, since it receives both long before the error occurs?

machineghost avatar Oct 08 '19 23:10 machineghost

@machineghost Thanks for your report 👍 It's definitely something we should try to address since I fully agree that current error gives you an absolute minimum of info. By default JS environments output description + call trace and we can't include a query or query variables into description since they can be huge and description is sent to the API client. However, I definitely agree that we should try to find solutions to provide more details in printed error messages.

At the moment we are in feature freeze due to the upcoming TS conversion but after it's done we will definitely try to address this problem.

IvanGoncharov avatar Oct 09 '19 13:10 IvanGoncharov

Awesome. Specifically, regarding:

By default JS environments output description + call trace and we can't include a query or query variables into description since they can be huge and description is sent to the API client.

Fair enough, but even just the first 100 characters of the query (maybe coupled with as many keys of the variables object as would fit?) would likely be enough to narrow down the source of the error in 95+% cases.

machineghost avatar Oct 09 '19 14:10 machineghost

@machineghost We already have custom toString() that output description + locations on all errors so you can do:

console.log(error.toString() + '\n\n' + error.stack)
Cannot return null for non-nullable field Query.id.

GraphQL request:3:5
2 |   {
3 |     id
  |     ^
4 |   }

Error: Cannot return null for non-nullable field Query.id.
    at completeValue (/dist/execution/execute.js:574:13)
    at completeValueCatchingError (/dist/execution/execute.js:509:19)

IvanGoncharov avatar Oct 09 '19 15:10 IvanGoncharov

But then you have to catch and log the error (specifically as a string) to see that info.

Surely you would agree that, just in general, it would be more convenient if a developer can 1) get an error, 2) immediately determine where it came from, without additional effort required?

And more importantly, wouldn't you also agree that if the entire problem is that you can't tell where the error came from in the first place, being able to get more info when you log it (AFTER you find it) isn't very helpful?

machineghost avatar Oct 09 '19 15:10 machineghost

@machineghost I definitely agree with all your points just wanted to specify that it's possible to do using the above workaround.

IvanGoncharov avatar Oct 09 '19 17:10 IvanGoncharov

This issue is still very much valid, the error messages are really not helpful at all. See the below one for instance - based on it I have no idea where to look or what to even look for :( image

Is there any work ongoing that is trying to remedy this?

Markus-ipse avatar Jun 18 '21 10:06 Markus-ipse

Feature-freeze over, this issue is open for business.

yaacovCR avatar May 22 '22 18:05 yaacovCR