Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Preserve stack track of original errors #561

Closed
5 of 9 tasks
bkeepers opened this issue May 15, 2018 · 11 comments
Closed
5 of 9 tasks

Preserve stack track of original errors #561

bkeepers opened this issue May 15, 2018 · 11 comments
Labels
auto-triage-stale enhancement M-T: A feature request for new functionality needs info An issue that is claimed to be a bug and hasn't been reproduced, or otherwise needs more info

Comments

@bkeepers
Copy link

WebClient.ts has several methods for wrapping errors from the client:

https://github.com/slackapi/node-slack-sdk/blob/master/src/WebClient.ts#L678-L718

All of them create a new Error, which means the stack trace that is returned when these errors occur is not very helpful to users of the SDK. For example, here's the error I'm currently trying to debug:

13:36:03.418Z ERROR event: A request error occurred: undefined
  Error: A request error occurred: undefined
      at requestErrorWithOriginal (/Users/bkeepers/projects/slack-app/node_modules/@slack/client/src/WebClient.ts:681:5)
      at got.post.catch (/Users/bkeepers/projects/slack-app/node_modules/@slack/client/src/WebClient.ts:145:21)
      at <anonymous>
      at process._tickDomainCallback (internal/process/next_tick.js:228:7)

This stackoverflow discusison has some options for preserving error.stack when wrapping errors.

What type of issue is this? (place an x in one of the [ ])

  • bug
  • enhancement (feature request)
  • question
  • documentation related
  • testing related
  • discussion

Requirements (place an x in each of the [ ])

  • I've read and understood the Contributing guidelines and have done my best effort to follow them.
  • I've read and agree to the Code of Conduct.
  • I've searched for any related issues and avoided creating a duplicate issue.

Reproducible in:

@slack/client version: 4.0.1

node version: 8.9.4

OS version(s): macOS 10.13.4

@aoberoi aoberoi added the enhancement M-T: A feature request for new functionality label May 15, 2018
@aoberoi
Copy link
Contributor

aoberoi commented May 19, 2018

my first thought is "why is the error message undefined, that should never happen!" i think that's probably worth looking into separately, so if you have any more information regarding how i might be able to reproduce this specific error, i'm very interested. i'll try to trace the possible code paths myself, but i'm not sure i have enough info.

but onto your actual point: i think you do have the entire stack trace, WebClient is calling into got, and that goes all the way down to process._tickDomainCallback() which is the top of the event loop. i think the real complaint is that there's no async stack trace. AFAIK, this is a problem with node itself. there are some libraries which exist to monkey-patch errors in order to provide a stack trace that survives async calls. i'm hesitant to adopt a third party monkey-patch solution because i know Chrome DevTools can do this, so there must be some mechanism in V8. if the solution that DevTools uses is available but just not surfaced in node yet, i'd prefer to wait for that to surface and adopt that (or inherit it for free).

if you have any concrete suggestions about which library or technique you'd like to see adopted, or any info to the contrary of what i know, i'm all ears!

@aoberoi
Copy link
Contributor

aoberoi commented May 19, 2018

it looks like if you were to reproduce your error with the inspector protocol enabled (--inspect) and the additional --inspect-brk is specified, you would get async stack traces. source: nodejs/node#16260

is this a solution for your problem? i think the resistance of using the async_hooks API to enable this all the time is that there is a performance overhead. if that's true, i wouldn't feel comfortable opting into that for the entire process from library code, that should be an application programmers choice.

@aoberoi
Copy link
Contributor

aoberoi commented May 19, 2018

others have referred to this package: https://github.com/amio-io/await-trace. i'm not sure how, or if, that will be useful.

@aoberoi
Copy link
Contributor

aoberoi commented May 19, 2018

as if this wasn't already complicated enough, another fact to keep in mind is that this project is compiled with typescript to target ES2015, where async/await are not available natively (the lowest supported node version, v6, cannot support this feature). therefore, any solution which specifically depends on async functions will not be available from this package.

i believe all the solutions powered by async_hooks (like using the inspector protocol) work with Promises, so the ES2015 compiler target should not limit them.

@aoberoi
Copy link
Contributor

aoberoi commented May 19, 2018

@aoberoi aoberoi added the needs info An issue that is claimed to be a bug and hasn't been reproduced, or otherwise needs more info label May 19, 2018
@aoberoi
Copy link
Contributor

aoberoi commented May 19, 2018

for reference, here's two errors i created from the WebClient just now. its notable that the error.code is quite descriptive. when there is an underlying error, the error.original value is also helpful.

{ Error: A request error occurred: ENOTFOUND
    at requestErrorWithOriginal (/Users/ankur/Developer/@slack/client/dist/WebClient.js:514:5)
    at got.post.catch (/Users/ankur/Developer/@slack/client/dist/WebClient.js:354:31)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:188:7)
  code: 'slackclient_request_error',
  original: 
   { RequestError: getaddrinfo ENOTFOUND slack.com slack.com:443
    at ClientRequest.req.once.err (/Users/ankur/Developer/@slack/client/node_modules/got/index.js:182:22)
    at Object.onceWrapper (events.js:315:30)
    at emitOne (events.js:116:13)
    at ClientRequest.emit (events.js:211:7)
    at TLSSocket.socketErrorListener (_http_client.js:387:9)
    at emitOne (events.js:116:13)
    at TLSSocket.emit (events.js:211:7)
    at emitErrorNT (internal/streams/destroy.js:64:8)
    at _combinedTickCallback (internal/process/next_tick.js:138:11)
    at process._tickCallback (internal/process/next_tick.js:180:9)
     name: 'RequestError',
     code: 'ENOTFOUND',
     host: 'slack.com',
     hostname: 'slack.com',
     method: 'POST',
     path: '/api/chat.postMessage',
     protocol: 'https:',
     url: 'https://slack.com/api/chat.postMessage' } }
{ Error: An API error occurred: not_authed
    at got.post.catch.then (/Users/ankur/Developer/@slack/client/dist/WebClient.js:383:62)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:188:7)
  code: 'slackclient_platform_error',
  data: 
   { ok: false,
     error: 'not_authed',
     acceptedScopes: [ 'chat:write:user' ] } }

@oleg-codaio
Copy link

oleg-codaio commented Aug 24, 2020

I wanted to bump this issue up, because we're having similar problems with the @slack/web-api package, running on Node 12 (the version that has V8 async traces enabled). For instance, here's a stack we're seeing:

Error: An API error occurred: account_inactive
     at Object.platformErrorFromResult (/project/node_modules/@slack/web-api/src/errors.ts:94:5)
     at WebClient.apiCall (/project/node_modules/@slack/web-api/src/WebClient.ts:188:13)
     at runMicrotasks (<anonymous>)
     at processTicksAndRejections (internal/process/task_queues.js:97:5)

This makes it difficult to trace which call to the Slack API in our code is failing.

An easy way to repro this locally is to edit WebClient.js and add console.trace() before and after the call to this.makeRequest():

const response = await this.makeRequest(method, Object.assign(

You'll notice that the first trace has the expected full stack, but the second one loses it. 🤔 This is definitely caused by axios (see axios/axios#2387), and may also be caused by the use of p-queue and p-retry.

The solution for this should be pretty straightforward: record the original stack trace within WebClient#apiCall, wrap its body with a try-catch, and in the catch block, append that original stack trace to the thrown error.

@stevengill
Copy link
Member

Thanks @vaskevich!

In general, I agree that including the proper stack trace in valuable.

I believe the solution you proposed though would have issues with debuggers such as vscode. It is also a little expensive to create a new error even when you don't plan on throwing the error every time the method is called.

Do you think there might be a different solution to this problem? Is Axios preventing us from taking advantage of node v8's async stack traces?

@oleg-codaio
Copy link

oleg-codaio commented Sep 3, 2020

I believe the solution you proposed though would have issues with debuggers such as vscode.

Could you go into detail more? Do you mean that VS Code would have trouble parsing the updated stack trace? If so, it should only be a matter of augmenting the stack trace properly.

It is also a little expensive to create a new error even when you don't plan on throwing the error every time the method is called.

The cost of network I/O from making API requests far exceeds the cost of creating an additional error object here, to the point where this additional allocation is insignificant, IMO.

Do you think there might be a different solution to this problem? Is Axios preventing us from taking advantage of node v8's async stack traces?

I can't really think of an alternative solution for making sure stack traces are preserved other than capturing the trace prior to the point that Axios breaks it. See this for more details: axios/axios#2387. A minor change could be to use Error.captureStackTrace instead.

@github-actions
Copy link

github-actions bot commented Dec 5, 2021

👋 It looks like this issue has been open for 30 days with no activity. We'll mark this as stale for now, and wait 10 days for an update or for further comment before closing this issue out.

@github-actions
Copy link

As this issue has been inactive for more than one month, we will be closing it. Thank you to all the participants! If you would like to raise a related issue, please create a new issue which includes your specific details and references this issue number.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
auto-triage-stale enhancement M-T: A feature request for new functionality needs info An issue that is claimed to be a bug and hasn't been reproduced, or otherwise needs more info
Projects
None yet
Development

No branches or pull requests

4 participants