laravel / cashier-mollie

MIT License
376 stars 63 forks source link

Issue with getOrder method in WebhookController #117

Open EvgeniyHablak opened 4 years ago

EvgeniyHablak commented 4 years ago

I've got an error while testing the webhooks

Undefined property: stdClass::$temporary_payment_id {"exception":"[object] (ErrorException(code: 0): Undefined property: stdClass::$temporary_payment_id at /var/www/wordproof/vendor/laravel/cashier-mollie/src/Http/Controllers/WebhookController.php:52)

And it seems like this is because of different properties in this places

Screen Shot 2019-11-28 at 11 46 33

But when i've set the same properties the order is not found by findByPaymentId using uuid. And thats why order status can't be updated.

This is how fixed version look but it works not as expected.

Screen Shot 2019-11-28 at 11 54 15
sandervanhooft commented 4 years ago

Thanks @EvgeniyHablak for reporting this. I have fixed the inconsistency in the develop branch.

Can you help me understand what's going on with the second part of your question?

sandervanhooft commented 4 years ago

ah found it

sandervanhooft commented 4 years ago

Dropped the 'temp_' prefix in the controller:

https://github.com/laravel/cashier-mollie/pull/113/commits/dda412f0ad1e0a6672730ad2358c3e2dff2725e9

EvgeniyHablak commented 4 years ago

We are almost there BUT now my mollie_payment_status is not updated to 'paid' I've tried to debug it but unsuccessful

sandervanhooft commented 4 years ago

Could you check:

EvgeniyHablak commented 4 years ago

Could you check:

  • the Mollie dashboard for the response they're getting when calling your webhookUrl?
  • your logs for any errors?

I've tried to debug library a little bit. when the lib version was 1.6 mollie made 2 requests and thats because our first response was with status code 500 (because we've tried to get mollie_payment_id from empty order object). after your fixes we are able to find order record in the database by temp payment id BUT I've Log that object we have found and it doesn't look like the order in my db. But how is that possible? Why for the first request from mollie we can't find the order but for the second one it works?

Here is one of response example Screen Shot 2019-12-02 at 16 35 05

Here is example of webhooks i received Screen Shot 2019-12-02 at 16 36 17

sandervanhooft commented 4 years ago

Mollie's webhook call is crazy fast. It's probably a concurrency issue. We'll have to look into it.

sandervanhooft commented 4 years ago

What cashier-mollie version are you at?

EvgeniyHablak commented 4 years ago

@sandervanhooft The debugging above is on version 1.6 And i'm currently on version 1.6 (because at least second webhook from mollie works fine)

sandervanhooft commented 4 years ago

Can you give 1.7 a try?

EvgeniyHablak commented 4 years ago

I have just checked it. I received one webhook from mollie and my response code was 200 BUT in my db molllie_payment_status is open

Also interesting thing is that i've tried to log the order in webhook Here is what ive got

Screen Shot 2019-12-04 at 17 43 54 Screen Shot 2019-12-04 at 17 43 16

But even if i die the script and would try to find such order with that temp id I couldn't

EvgeniyHablak commented 4 years ago

Maybe i'm testing incorrectly This is how my flow looks like:

  1. changing the date order_items.process_at from (for example) 2020-12-12 to 2019-12-12
  2. running php artisan cashier:run
  3. received the webhook and process the request somehow
sandervanhooft commented 4 years ago

Hi @EvgeniyHablak,

  1. It seems the $order is resolved just fine?
  2. In test mode, Mollie does not update payment status for mandated payments. You however can update it manually using your browser. There's a _link embedded on the payment specifically for this reason. I usually grab it using mollie()->payments()->get("the_payment_id")->_links;
EvgeniyHablak commented 4 years ago

Hi @sandervanhooft ! Thanks! I'll check it out asap

sandervanhooft commented 4 years ago

Closing this for now, let me know if it should be reopened @EvgeniyHablak .

Paulsky commented 4 years ago

I don't want to hijack this issue, but I also have some issues with the default Webhook callback. The getOrder function returns always null (can't find by mollie_payment_id). Could it be that the Webhook is called before the Order actually exists in the database.....? In this case the webhook is called after swapping a plan.

sandervanhooft commented 4 years ago

@Paulsky what version are you using?

Paulsky commented 4 years ago

I'm using v1.10.3

Paulsky commented 4 years ago

Just to make things clear (maybe I'm doing something wrong):

I'm using the swap() function on an existing subscription. The webhook is called correctly, and the data in the Mollie dashboard looks also correct. When I manually check the database, the mollie_payments_status is 'open' and the 'mollie_payment_id' is filled. The Order before the swap, created with the newSubscription, is 'paid'. The given payment ID with the request is set and looks correct. But as I said, maybe the Order doesn't exists at the time of the webhook call? Because Order::where('mollie_payment_id', $id)->first(); returns null.

Paulsky commented 4 years ago

So I did a lot of debugging. The Order is found in the webhook function, if I remove the DB::transaction() wrapper in the Subscription restartCycleWithModifications() function.

This way, the handlePaymentPaid() is called in the webhook and the OrderPaymentPaid event is fired. So that's great (for sending a new invoice).

But, somehow, the order status is still 'open', even though $this->update(['mollie_payment_status' => 'paid']); is called.

Hope this helps you understand my issue a little bit!

Paulsky commented 4 years ago

I know you are very busy @sandervanhooft , and I don't want to push you. But maybe you can re-open this issue...?

sandervanhooft commented 4 years ago

I have been thinking about this...

The transaction is there for a reason. It's good to disable it to understand the problem, but I think we should keep it there.

As I've discussed here, there are essentially two alternatives we can try:

  1. when the webhook is called, return a 404 if the payment is not found. Mollie will retry the webhook a second later, and then again using increasing intervals.

  2. keep on returning a 200 response, but handle the webhook call in a queued Job, effectively enforcing a retry scheme within the app.

For simplicity and ease of debugging, I'm leaning towards option 1. What do you think, @Paulsky et al?

Paulsky commented 4 years ago

Hmm, I'm not sure. I'm also leaning towards option 1.

But, the problem I have is that I don't understand the reason why this is happening. Why is the Order not found (while it really seems to exists in the db)? Maybe if I understand the reason, I can give a better suggestion. Do you know what the problem is and could you explain it to me?

Thank you @sandervanhooft 🙏

Edit: I thought I have read somewhere that you wrote that the Mollie webhook is too fast. But I'm not sure about that myself; why would the Order be found if the DB:transaction wrapper is removed? This shouldn't speed up the webhook code would it? Or am I wrong about this?

sandervanhooft commented 4 years ago

It's a race condition issue.

Mollie's webhook call is so crazy fast it calls the webhook before the transaction is finished (meaning the Order is not stored yet). This all happens in a fraction of a second. So to the human eye it seems like the Order already is in the database table. But in fact, it's not stored yet.

Paulsky commented 4 years ago

Alright, incredible! If that's the case and if the DB::transaction wrapper can't be removed (I don't know if this is even the problem) I also recommend option 1; return a 404 because the Order really does not exists right? It feels less hacky and a lighter solution (instead of forcing users to use queues right?)

sandervanhooft commented 4 years ago

Exactly @Paulsky , thanks!

sandervanhooft commented 4 years ago

@Paulsky is this is issue occurring in test or live mode?

Paulsky commented 4 years ago

This occurs in test mode. But live I'm not sure, because I just saw I have some 'paid' 'mollie_payment_status' in the live database.

sandervanhooft commented 4 years ago

Ok, any of them not marked as paid that should be?

Paulsky commented 4 years ago

No, it looks correct at live!