search

Expensify / App

Welcome to New Expensify: a complete re-imagination of financial collaboration, centered around chat. Help us build the next generation of Expensify by sharing feedback and contributing to the code.
https://new.expensify.com
MIT License
3.14k stars 2.64k forks source link

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

Open blimpich opened 4 weeks ago

blimpich commented 4 weeks ago

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[bot] commented 3 weeks ago

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

melvin-bot[bot] commented 3 weeks ago

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

melvin-bot[bot] commented 3 weeks ago

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

melvin-bot[bot] commented 2 weeks ago

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

melvin-bot[bot] commented 2 weeks ago

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

dangrous commented 2 weeks ago

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:

image
blimpich commented 2 weeks ago

@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 commented 1 week ago

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 commented 1 week ago

eyyy finally managed to reproduce. Looking into it now.

dangrous commented 1 week ago

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 commented 1 week ago

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

dangrous commented 3 days ago

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 commented 3 days ago

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:
image
  1. 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:
image

Hope that helps!

dangrous commented 3 days ago

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 commented 2 days ago

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 commented 2 days ago

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"

image
blimpich commented 2 days ago

@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 commented 2 days ago

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 commented 2 days ago

I think STimeNow() is perfectly sufficient 👍

dangrous commented 2 days ago

okay that PR is up

dangrous commented 1 day ago

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

trjExpensify commented 1 day ago

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

blimpich commented 1 day ago

Looks like its deployed 🎉

dangrous commented 10 hours ago

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 commented 10 hours ago

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