[Payment history] make refund receipts have correct dates when refunded directly via stripe

[blimpich]

Problem:

Refund date is showing at Jan 1st 1970 on refund receipts.

Reproduction steps:

1. create new account on Old Dot with an email that you have access to
2. create new annual subscription with a non-zero user count (ex: 5)
3. add a valid stripe test card to the user's Account > Payment > Payment Details
4. from the cli, run billing using script/clitools.sh billingrun
5. run php script/notifyall.sh from inside the VM in Web-Expensify
6. make sure script/bwm.sh is running so that the subsequent BillingReceiptUploader job can complete
7. confirm you get a billing receipt
8. comment out these lines of code from the ProcessStripeWebhook command
9. recompile and restart auth
10. look in the purchases table at the most recent purchase (should be the one you just made) and find the transactionID value. It'll be a hashed value, not the actual transactionID.
11. run the following commands from the VM, careful to replace YOUR_TRANSACTION_ID_HERE with your actual transaction id that you got from the purchases table

nc localhost 4444

ProcessStripeWebhook
eventType: charge.refunded
signature: whsec_8V8HYuNqeMDTgMUdwdGxWygHda7tE2Sx
payload: {"id":"evt_1CA23QKMVuTn5qYVgNZ14TBq","created":1522096592,"data":{"object":{"id":"YOUR_TRANSACTION_ID_HERE","amount":900,"amount_refunded":900,"created":1522096552,"currency":"usd","description":"Refund Test","refunds":{"object":"list","data":[{"id":"re_1CA23QKMVuTn5qYVUgS8I1Mr","object":"refund","amount":900,"balance_transaction":"txn_1CA23QKMVuTn5qYVQXlC0CAx","charge":"ch_1CA22mKMVuTn5qYVQitM5R1L","created":1522096592,"currency":"usd","metadata":[],"reason":"requested_by_customer","receipt_number":null,"status":"succeeded"}],"has_more":false,"total_count":1}}},"type":"charge.refunded"}
countryISO: US

12. run notifyall.sh again and make sure bwm is still running
13. confirm that you got an email about a refund
14. see that that refund shows Jan 1st 1970 as the refund date

Solution

Investigate and fix this.

[melvin-bot]

Whoops! This issue is 2 days overdue. Let's get this updated quick!

[melvin-bot]

Eep! 4 days overdue now. Issues have feelings too...

[melvin-bot]

Still overdue 6 days?! Let's take care of this!

[melvin-bot]

10 days overdue. Is anyone even seeing these? Hello?

[melvin-bot]

12 days overdue now... This issue's end is nigh!

[dangrous]

Skimming for issues I can take... Do you still see this happening? Just from the refund that I got for testing that other thing (ha), I see the correct date:

[blimpich]

@dangrous huh, not sure! Where did you do the refund from? Was it from supportal or the stripe dashboard? I think the date is only wrong when we refund directly via stripe, which is what the repro steps simulate. But I haven't tried repro-ing since I created this issue so maybe not.

Can you try the repro steps and see if it reproduces?

[dangrous]

oh interesting. Yeah it was via supportal. If I have time today I'll try to go fully through the steps! It was giving me a bit of trouble on Friday but I've rebuilt since then so it's maybe better haha

[dangrous]

eyyy finally managed to reproduce. Looking into it now.

[dangrous]

Okay so it's this line: https://github.com/Expensify/Auth/blob/ce419dee8d3327b51569f728ce3da131b90f628b/auth/command/ProcessStripeWebhook.cpp#L198

Basically SComposeTime deals with usecs, not regular seconds, so it's not correctly parsing the date response from Stripe (i.e. it's saying 1000x less time has passed).

I just need to figure out the right function to use to parse, I'm sure we have one in there.

[dangrous]

Technically can fix by multiplying the purchase date by (uint64_t)1000000 but i feel like there's probably a better way

[dangrous]

ugh I would prefer not to have to create a third set of test accounts and real transactions on my real card for this.

@trjExpensify any chance you know of a way we could just double check that any real refunds we're already sending out are appropriately timestamped? Check with concierge agents maybe?

It should be all set, but I'd like to QA to confirm

[trjExpensify]

Hm, any manual refund requests should get a GH created to process by Conci. Doesn't look like we've had any new ones since this was deployed: https://github.com/search?q=repo%3AExpensify%2FExpensify+refund+request&type=issues

So I think our best bet is to look for refunds in the logs probably, yeah?

1. Your PR hit prod yesterday at ~5.45pm UTC: https://github.com/Expensify/Auth/pull/11590#issuecomment-2229054799
2. When we refund someone, we should trigger Notification_RefundReceipt here: https://github.com/Expensify/Web-Expensify/blob/37dbd9df87740a4c4afd91c4edd86862b9090113/lib/UserAPI.php#L3452-L3489
3. I searched the logs for the past two days, and found this one processed yesterday at 22.12 UTC
4. Supportal'd into the customer account (not incl. credentials here in /app) and can see this receipt in the account:

5. Not sure why the receipt says refunded on 1st July, 2024 when in fact it was refunded on 15th July, which the billing history in account settings confirms:

Hope that helps!

[dangrous]

Ooh great, that's helpful! But shows that we might be using the wrong date here - the date of the charge, not the date of the refund itself. So, we're close, but no cigar (might not have noticed this testing since the date of the charge and the date of the refund were the same).

@blimpich can you chime in on what we intended here? Asking because we specifically use notification["refundDate"] = originalPurchaseDate; here. Was that intentional? Should the refund date equal the original purchase date? Or is that a separate bug that is now surfaced and needs to be fixed?

[trjExpensify]

Yeah, I think it's inaccurate to say "Refunded on X date" and that date not be the date of refund. So we should change that to the date refunded, as it's in the design doc. 👍

[trjExpensify]

Worth noting we're adding the card number portion to this as well, so it'll be even weirder to have "Refunded on July 1st 2024 to card ending in 1234"

[blimpich]

@blimpich can you chime in on what we intended here? Asking because we specifically use notification["refundDate"] = originalPurchaseDate; here. Was that intentional? Should the refund date equal the original purchase date? Or is that a separate bug that is now surfaced and needs to be fixed?

Not intentional, very much a mistake 🫠

[dangrous]

Okay cool I'll see if I can spin up a fix for this shortly! I think we can just use SComposeTime("%Y-%m-%d %H:%M:%S UTC", STimeNow()) - @blimpich would this code ever run at a different time other than immediately after the refund is processed? Trying to figure out if that would be sufficient. I can also see if there's another piece of the data returned from Stripe that I can use.

[blimpich]

I think STimeNow() is perfectly sufficient 👍

[dangrous]

okay that PR is up

[dangrous]

Once that's on prod I'll use your test steps @trjExpensify to see if we're good to go!

[trjExpensify]

Dope, we're deploying auth now, so shouldn't be too long. 👍

[blimpich]

Looks like its deployed 🎉

[dangrous]

doesn't look like we've processed a refund yet if I'm calculating UTC correctly. I believe we're shooting for something after July 18 6:40PM UTC and the last one we have is 2024-07-18 16:20:43.

I mean hopefully we never need to refund anyone ever again and we NEVER KNOW

semi-related - I would LOVE a toggle in log search to show times in local time.

[trjExpensify]

Move to the UK man.. for half the year you'll be on UTC. 😂

[dangrous]

Good/bad news - still no new refunds, so can't confirm nor deny

[dangrous]

Okay so I found one - https://www.expensify.com/_devportal/tools/logSearch/#query=request_id:(%22393Ikb%22)+AND+timestamp:[2024-07-22T16:12:42.041Z+TO+2024-07-22T18:12:42.041Z]&index=logs_expensify-029493

Weirdly, the pdf refund is still saying July 1, which is particularly odd because neither the original charge (July 7) nor the refund (July 22) is on that date. I double checked the code though and there's pretty much no way that should have happened, with what I updated. @blimpich do you happen to know if the pdfs are separate code? Like, did I fix it for the email but not the pdf? I didn't realize that if so.

Sorry this is dragging on so much.

[blimpich]

The issue is probably that there are three different ways of creating a receipt, and one of them is probably broken. The three ways are:

1. an expensify employee refunds directly via Stripe
2. a expensify employee or support staff (second responders I think) refund via supportal
3. the user themselves refunds via the "request refund" button on the payment page

#2 & #3 use similar logic, but #1 is almost an entirely separate flow. This issue's reproduction steps focus on #1. I bet that refund was through #2 or #3. We'd need to create a refund locally via supportal or the request refund button to confirm that hypothesis, but that is my guess as to what is going on.

And no apologies needed! I'm dealing with the same frustrations over in this PR. Niche billing code + notification QA is a recipe for a bad time 🫠

[dangrous]

Oh okay I think I've figured it out, mostly - you're right. so for case 1, the notification is sent from from Auth, and we fixed that code. For both 2 (UserAPI::refundUser) and 3 (UserAPI::refundPurchase), the notification is sent from PHP. Both of those call UserAPI::createRefundReceipt which basically makes the same mistake that we did - they pull the created date of the original purchase, NOT the refund, and use that as the refund date. I think this might be an Auth bug - I think it should be sending back the purchase ID of the refund, not the original purchase.... BUT I'm not sure if there's other code relying on it so to be safe I'll see if we're already sending the refund date somewhere else, and use that rather than changing what Auth sends.

[dangrous]

I will have to figure out how to fake those types of refunds on dev though, lemme know if you have tips.

[dangrous]

Weirdly, the pdf refund is still saying July 1, which is particularly odd because neither the original charge (July 7) nor the refund (July 22) is on that date. I double checked the code though and there's pretty much no way that should have happened, with what I updated.

oh and it's always the first of the month when sent from PHP because for some reason we take the date, convert into just a month and year string (like July 2024) when we send it to the notification, and then change that string BACK to a month day year inside the notification code. But since there's no longer a day in it, it defaults to the first of the month. Le sigh.

[dangrous]

Okay I made a draft PR - https://github.com/Expensify/Web-Expensify/pull/42878

Two questions for the room:

• Should I create a new issue? Technically this one is only for "when refunded directly via stripe". We still haven't successfully QAd because we haven't found a matching refund, but the new issue is a separate bug.
• @blimpich I can get the notification code to run successfully (I think) on dev, but it never actually sends the email or creates the refund receipt for view in the app. This happens on main as well as my branch, so it's not the new code. Any thoughts on how to test this fully? It's hitting my breakpoints and making the notification, but it never sends, even with BWM` running and after running the notifyall script in the vm.

[blimpich]

I think it'd be fine to create a new issue. Probably help keep us all sane. Maybe reword the issue title of this too to make it clear this is just for stripe refunds. I probably should've done that to begin with.

For the second point, hmmmm, that's strange. I'll DM you, maybe we could do some paired programming? I know that I've tested those flows locally before, so I know its possible.

[dangrous]

great, made https://github.com/Expensify/Expensify/issues/415121, we'll continue discussion there

As for this, we're still waiting on a Stripe activated refund to QA

[dangrous]

Okay so I've found a Stripe refund, but unfortunately the receipt link in the billing history links to the original receipt, not the refund. Is there another way to look at it?

[blimpich]

Did you look at the expenses view? If the refund went through correctly it should have made an expense with the receipt for the refund attached to it.

[dangrous]

that one looks like it didn't go through.

BUT (drumroll please) I did find one that DID go through!

Looks like it's working! Closing out.

[blimpich]

Oh yay!!!