Charges sometimes requested with no POST body

[craigandrews]

Go version: 1.12.5
Stripe Go version: v61.0.1

Receive Stripe error code parameter_missing with failure Must provide source or customer. This happens sporadically, about 0.5% of the time (18 out of 3150 charges this morning). On looking at the Stripe developer logs dashboard I see that the request had no POST body at all.

Retrying the transaction with the exact same code works fine.

Client code is pretty standard:

	// Create the charge in Stripe
	chargeParams := &stripe.ChargeParams{
		Amount:      stripe.Int64(amount),
		Currency:    stripe.String(string(currency)),
		Description: stripe.String(description),
		Customer:    stripe.String(customerToken),
	}
	chargeParams.AddExpand("balance_transaction")

	if idempotencyKey != "" {
		chargeParams.SetIdempotencyKey(idempotencyKey)
	}

	ch, err := charge.New(chargeParams)

Can confirm that all values are set properly as they are logged just before creating the charge. And again, retrying seems to work.

[brandur-stripe]

Hi @candrewsmtn, sorry to hear about the trouble.

This is definitely a weird one. This probably isn't what you want to hear, but this is most likely a bug in your code somewhere — if you pass a nil params into charge.New, the underlying Call will silently skip over that input and allow the API itself to complain, producing exactly the same error that you're seeing:

2019/05/28 15:21:33 Error encountered from Stripe: {"code":"parameter_missing","status":400,"message":"Must provide source or customer.","request_id":"req_Xd6WU9vN1HEwA9","type":"invalid_request_error"}

Can you further audit your code to make sure that chargeParams couldn't possibly be getting set to nil somewhere?

Even if you're sure that it's not possible, I think we're still going to need to come up with a way to reproduce this. I took a look through the code in question and there's nothing obvious to me that would cause it, so we'd need to try and localize the problem.

Do you have any ideas on how we might be able to repro? Have you noticed any patterns around the failed requests? (Do they all happen near the beginning of the app's lifecycle? Are they roughly distributed throughout its lifetime?) Thanks!

[layby42]

Hi Everybody, got same error with version 60.13.1 about 2 weeks ago, happened several times on attempt to put amount on hold. Our on-hold code is quite old, all we did is upgraded stripe-go lib. I've never saw this error before, was not able to find what could be wrong with our code. My guess was maybe issue related to payment intents recently introduced by stripe (maybe customer's CC requires extra steps or customer does not have default CC at all). We ended up with notifying clients that on-hold attempt was not successful to let them manually resolve the issue in case of Must provide source or customer. No complains so far, so we still do not know what it was.

[brandur-stripe]

@layby42 Oh interesting. Can you let us know what version you upgraded from just to give us a baseline to compare with?

[layby42]

@brandur-stripe we've upgraded from v 55.14.0

[craigandrews]

Hi @brandur-stripe

Unfortunately the code snippet I posted is verbatim from the only place in the codebase that we create charges. It's a small microservice that listens on an MQ and processes charges we throw at it.

The errors are sporadic, not particularly evenly spaced, spread throughout the lifetime of the process, and don't appear to have anything in common with other failing charges. All the charges worked fine on retry with the same idempotency key and body.

We have also done some V&P testing with much higher volumes than we're currently seeing (approx 80 charges per second, whereas we're currently at around 20) using a v60 version against the test system and never saw this error. This has only started in the last 3 days.

[brandur-stripe]

We have also done some V&P testing with much higher volumes than we're currently seeing (approx 80 charges per second, whereas we're currently at around 20) using a v60 version against the test system and never saw this error. This has only started in the last 3 days.

So weird!

V61 was actually a no-op in that all did was upgrade the target server-side Stripe version. There weren't any local changes.

Do you think you could give me the request ID (i.e. req_) of one of the failed requests? I want to rule out a possible server-side problem.

[craigandrews]

Sure, this is the most recent one: req_jnhzXY9ayWbiak

[brandur-stripe]

Thanks!

Just a quick follow up that I was able to reproduce this without too much trouble with a fairly simple charge creation script running for a few minutes:

package main

import (
	"fmt"
	"math/rand"
	"time"

	"github.com/stripe/stripe-go"
	"github.com/stripe/stripe-go/charge"
)

func createChargesForever() {
	for {
		chargeParams := &stripe.ChargeParams{
			Amount:   stripe.Int64(123),
			Currency: stripe.String(string("USD")),
			Customer: stripe.String("cus_F9WZt8VGADqzaQ"),
		}

		_, err := charge.New(chargeParams)
		if err != nil {
			panic(fmt.Sprintf("error = %v\n", err))
		}

		time.Sleep(time.Duration(rand.Intn(100)) * time.Millisecond)
	}
}

func main() {

	stripe.DefaultLeveledLogger = &stripe.LeveledLogger{
		Level: stripe.LevelError,
	}
	stripe.Key = "sk_test_..."

	for i := 0; i < 10; i++ {
		go createChargesForever()
	}

	<-make(chan struct{})
}

I was printing payloads throughout, so I'm pretty sure this isn't related to stripe-go in particular. We may be dropping parameters somewhere else.

[brandur-stripe]

Alright, I'm pretty sure this is related to HTTP/2 again. If I rerun with it off, suddenly I can no longer reproduce:

$ GODEBUG=http2client=0 go run main.go

I'll try to localize it to either a problem on the server end or a problem in the Go HTTP/2 stack.

[craigandrews]

Ah that's interesting. I wondered if it was something to do with concurrency and persistent connections but I'd expect the Go stack to handle that. Thanks for looking into it. For now I am just detecting when the problem occurs and putting the request back onto the MQ to retry later but if I can fix it with a single env var for now that might be enough.

[brandur-stripe]

(Apologies for the silence on this issue — I had some trouble diagnosing the problem and forgot to hand it off before a few weeks away. I'm now pulling in some internal help to figure it out.)

[craigandrews]

No problem. Disabling the http2 client resolved it well enough for our purposes.

[brandur-stripe]

Disabling the http2 client resolved it well enough for our purposes.

Oh, good to know! Thanks for following up.

[brandur-stripe]

Sorry about the long silence on this one everyone.

We had someone investigate internally, and after confirming that the problem doesn't seem to be specific to stripe-go, we are pretty sure that it's this bug in Go's HTTP/2 implementation:

golang/go#32441

We've bumped the bug with some more information, and hopefully we'll see some progress on it soon. In the meantime, we are going to disable HTTP/2 by default in stripe-go (and will re-enable it when the bug is fixed): #903

If you don't want to upgrade, you can achieve something similar by using an HTTP client (set with SetHTTPClient or BackendConfig.HTTPClient when using GetBackendWithConfig) with its Transport.TLSNextProto set to a non-nil, non-empty map like so:

&http.Client{
	Transport: &http.Transport{
		TLSNextProto: make(map[string]func(string, *tls.Conn) http.RoundTripper),
	},
}

(Although it looks like a lot of you already knew this ;)

I'm going to leave this issue open for continued tracking.

[abh]

Looks like the Go issue has been fixed in 1.15-tobe and will be back ported to the next minor 1.13 and 1.14 releases.

🥳 🥂

[brandur-stripe]

@abh Yes!! So exciting, especially because the issue was getting no traction for so long. Can't wait, haha.

[craigandrews]

Excellent news! As it happens I only recently revisited this bit of code and switch from the env var to the custom HTTP client to get around it. Wondered if it had ever got anywhere.

[brandur-stripe]

Going to call this one fixed as of #1156 / stripe-go 71.45.0. You must be on Go 1.15+ for HTTP/2 to be re-enabled since the Go core backports for the fix didn't seem to making fast progress, but we expect that it will eventually be re-enabled for all support Go versions as the language continues to move.

Thanks for the input everyone!