stripe-node icon indicating copy to clipboard operation
stripe-node copied to clipboard

Requests not aborted within timeout

Open conner-smith-anrok opened this issue 9 months ago • 5 comments

Describe the bug

I've noticed that the elapsed value in the Stripe.ResponseEvent sometimes exceeds the configured timeout by up to 15 seconds. I'm wondering if the request isn't being aborted within the timeout due to some bug in the timeout logic or if i'm misunderstanding how the timeout works

To Reproduce

Not deterministic, but the set-up is like this:

  • Initialize a Stripe client using a global timeout (e.g. 10 seconds)
  • Subscribe to Stripe.ResponseEvents. In the event handler, log elapsed field from each response event,
  • Send some requests over a period of time. Observe that the elapsed time for some requests exceeds the timeout

For perspective, we don't see this frequently. Over the past week, we've seen this in roughly 20 out of 10 million requests.

Expected behavior

Request aborted within the timeout or help me understand why the elapsed time is up to 15 seconds longer than the timeout

Code snippets

new Stripe(apiKey, {
    apiVersion: `2024-06-20`,
    stripeAccount: stripeAccountId,
    timeout: 10_000,
    maxNetworkRetries: 2,
});

stripe.on('response', (event: Stripe.ResponseEvent) => {
    console.log(`${event.elapsed}`); // sometimes as high as 25s
});

OS

linux

Node version

Node v22.14.0

Library version

stripe-node v16.7.0

API version

2024-06-20

Additional context

I can provide request IDs if that would be helpful, but this seems related to client-side code

conner-smith-anrok avatar May 06 '25 21:05 conner-smith-anrok

Here's a request ID with an elapsed time of 25s - req_VgcdomTlIg2WRC. Might be helpful to know how long the request took from the server side

conner-smith-anrok avatar May 07 '25 16:05 conner-smith-anrok

Hi @conner-smith-anrok , sorry for the delay in following up! We have an issue logged internally and will take a look as soon as we can! How big of an issue is this for you at the moment?

jar-stripe avatar May 16 '25 16:05 jar-stripe

thanks @jar-stripe!

this is a medium issue - the impact is that we run most of our logic after acquiring a DB connection and beginning a DB transaction, so we're holding a scarce resource idle and increasing the chance of DB serialization issues. we would rather abort the request when the timeout is reached and retry later.

conner-smith-anrok avatar May 27 '25 18:05 conner-smith-anrok

Hi @conner-smith-anrok! Thanks for all the details here -- I was looking into this but we don't seem to have logs for the previous request available. Do you have any other other recent request IDs I could use to take a look? Also, have you observed any patterns with the types of requests that cause this to occur? I suspect that this may be because this timeout is not a total request timeout but a connection timeout -- but it'd be helpful to take a look at what's going on server-side.

helenye-stripe avatar Jun 03 '25 17:06 helenye-stripe

Hi @conner-smith-anrok: following up here on @helenye-stripe 's questions. If you have any recent request IDs you can send for us to look at and/or any observations about patterns in which this can pop up, that would be great! Thank you!

jar-stripe avatar Jun 18 '25 19:06 jar-stripe

here are a few recent ones:

timestamp requestId elapsedMs
2025-06-25T23:14:26.526515Z req_iNiRM6eVPZ1ghY 28233
2025-06-26T23:58:18.982687Z req_8mZuj5PCAIK9Ey 27000
2025-06-26T04:22:52.948652Z req_mCICFI6VGGEHq6 26887
2025-06-26T23:14:30.670006Z req_GXPHiUqQK6L6A7 24496

do these match any logs on your end?


I suspect that this may be because this timeout is not a total request timeout but a connection timeout

possibly. it has been a while since i looked at the SDK code, but my understanding was that the SDK only supports a single timeout parameter and this would be the max total time spent on a request (connection + request timeout). should i be using a different strategy to get that desired behavior?

conner-smith-anrok avatar Jun 30 '25 19:06 conner-smith-anrok

Unfortunately I've tried to reproduce this locally and look into the requests, but I haven't been able to reproduce to the same extent of 2.5x the given timeout. I had a brief hypothesis that this may have been due to retries, as I looked into the logs for one request above and there was a longer request that returned with an error and a Stripe-Should-Retry: true header, and the retry was that request. However, in testing the elapsed times only included the successful retry, which was short. I also tried adding delays for receiving a response after connection but still hit the timeout.

We may need some help with additional investigation as I do not inherently see anything wrong with the SDK and server-side behavior. Is there any additional logging for these requests on your end? Is there any suspicious behavior, such as network or system load?

helenye-stripe avatar Jul 14 '25 16:07 helenye-stripe

hmm okay. feel free to close this ticket; i'll re-open or make a new one if i find something. thanks!

conner-smith-anrok avatar Jul 17 '25 16:07 conner-smith-anrok