workflow payment status gets clobbered - stale order object - bad bug

Submitted by lutegrass on Thu, 12/06/2007 - 08:36

Posts: 167
Joined: 10/08/2007

After enabling the new default "Update order status on full payment" workflow, I see this in the order log after a successful paypal ipn payment ...

- PayPal payment for $10.00 entered by -.
- Order status changed from in_checkout to payment_received
- Checkout message sent to foo@...

and then the killer

- Order status changed from payment_received to pending

This all happened before I clicked to go back to the store from paypal so it's not related to the complete checkout return. The ipn code is doing all of this. The payment workflow is seeing balance zero and setting the appropriate status. But change to pending clobbers it. Here's the culprit in uc_cart.module line 1761:

  // Move an order's status from "In Checkout" to "Pending"
  if (uc_order_status_data($order->order_status, 'state') == 'in_checkout') {
    uc_order_update_status($order->order_id, uc_order_state_default('post_checkout'));
  }

I have the new default uc_payment workflow installed which is doing its thing and then getting clobbered by the above code. The status check appears to be stale or bad since the status has already been changed to payment_received, but it still thinks it's in_checkout. The problem will be solved, I think, if the order status check was done directly against the database. The payment workflow is firing after an ipn comes in and then it updates the status, but it's not getting updated in the passed order object.

Changing this code slightly to this ugly hack:

$tmporder = uc_order_load($order->order_id);
 
  // Move an order's status from "In Checkout" to "Pending"
  if (uc_order_status_data($tmporder->order_status, 'state') == 'in_checkout') {
    uc_order_update_status($order->order_id, uc_order_state_default('post_checkout'));
  }

seems to fix the race condition. Does uc have any sort of real-time order status api call?

This bug happens with the latest bazaar. Workflow and ipn affect other places in the code too! Some sort of api to check actual status should be used throughout.

Christopher Schaub
LuteGrass, LLC
http://www.lutegrass.com

permalink #1 Thu, 12/06/2007 - 11:23

lutegrass

Posts: 167
Joined: 10/08/2007

I think this stale order object was also causing items to get left in the cart because an order in "pending" status will cause a redirect to the cart. So, when the user returns from paypal, their order is "pending" when it should be either in_checkout or payment_received.

Christopher Schaub
LuteGrass, LLC
http://www.lutegrass.com

permalink #2 Thu, 12/06/2007 - 13:52

torgosPizza

Posts: 1293
Joined: 08/14/2007

Wow - good catch. I have seen this bug and would like to get the Überdudes' thoughts on this. Thanks for scharing, schaub!

"Pain don't hurt." - Dalton

Mike Nelson's RiffTrax! www.rifftrax.com

permalink #3 Thu, 12/06/2007 - 17:25

lutegrass

Posts: 167
Joined: 10/08/2007

I'd love if anybody could point out something wrong with my hack above. I'm not suggesting it's a final solution, just looking for holes. Going live tomorrow and really needed a fix -- so I hope it's good to go for now.

Christopher Schaub
LuteGrass, LLC
http://www.lutegrass.com

permalink #4 Thu, 12/06/2007 - 17:35

Ryan

Posts: 5269
Joined: 08/07/2007

Investigating the issue right now... while doing it I noticed I can screw up checkout by changing my cart contents in another tab while going through checkout in another. Fun stuff! Sticking out tongue (Fixed by wiping the cart_order session variable on a cart update or item add to cart; will commit before I leave today.)

permalink #5 Fri, 12/07/2007 - 22:28

lutegrass

Posts: 167
Joined: 10/08/2007

Just checking in to see if you made any progress -- I know, Drupal upgrades! Smiling

This is a very nasty bug to track down because you have to have a stateless condition like ipn to see it happen. I'm concerned that it's a much bigger problem than ipn though -- anything using workflow to update a status can update the database and then running objects will potentially be out of date. An easy way to see the bug is to put a watchdog statement and compare statuses in the database and those in the order object right before the switch to pending in uc_cart. The order object, many times, will still think it's "in checkout" while the new paid in full workflow has already updated it in the db to be "payment received." The real problem tracking this down is that if ipn is really slow coming back, it will look like there's no bug -- or if you don't have ipn setup to return. Hope this helps.

http://www.christopherschaub.com

Christopher Schaub
LuteGrass, LLC
http://www.lutegrass.com

permalink #6 Fri, 12/07/2007 - 22:53

lutegrass

Posts: 167
Joined: 10/08/2007

Ok, I'll take it further because I'm nuts. In uc_paypal.module, handling the incoming ipn, you call uc_payment_enter() right before you call uc_cart_complete_sale($order). uc_payment_enter() fires the payment workflow as its last task. Boom, the status is now "payment_received" and you're passing an $order object that thinks it's "in checkout". This will cause items to be left in the cart on return and payment statuses to get clobbered back to pending after payment as been received.

from uc_paypal_ipn :

case 'Completed':
          $comment = t('PayPal transaction ID: !txn_id', array('!txn_id' => $txn_id));
          uc_payment_enter($order_id, 'paypal_wps', $payment_amount, $order->uid, NULL, $comment);
          uc_cart_complete_sale($order);

My fix is just a hack to keep the lights on, I know it needs a better fix. Ok, it's bourbon time in Nashville! Shocked

Christopher Schaub
LuteGrass, LLC
http://www.lutegrass.com

permalink #7 Wed, 12/19/2007 - 10:02

Ryan

Posts: 5269
Joined: 08/07/2007

Ahh, I see now what you mean. My hunch is this is the real culprit. Perhaps I should've made the uc_cart_complete_sale() function receive the order ID instead of the full order object. And now it's stuck in around a dozen different modules. Sticking out tongue I suppose for the time being I'll have that func load the current order status. For your other hack, I'd change it to this, too, instead of a full order load:

<?php
  $status = db_result(db_query("SELECT order_status FROM {uc_orders} WHERE order_id = %d", $order->order_id));
?>

<unrelated>Also, how in the world did I ever miss your music? It's great! I'm sure my dad would love it, too... he does banjo/fiddle and loves bluegrass. I'm sure he'll dig "Lutegrass" when I send him the link. All interested: hear schaub123's excellent lute/tenor voice Smiling </unrelated>

permalink #8 Wed, 12/19/2007 - 11:08

lutegrass

Posts: 167
Joined: 10/08/2007

Thanks for the kind words and the fix. I just moved to Nashville to play more bluegrass and original lute songs -- loving it down here!

Christopher Schaub
LuteGrass, LLC
http://www.lutegrass.com

permalink #9 Wed, 12/19/2007 - 11:25

Ryan

Posts: 5269
Joined: 08/07/2007

n/p, thanks a lot for doing all the digging. I also changed the function uc_order_condition_status() in uc_order_workflow.inc:

<?php
  // Check the current order status.
  function uc_order_condition_order_status($order, $settings) {
    // Return TRUE if the order status matches.
    $status = db_result(db_query("SELECT order_status FROM {uc_orders} WHERE order_id = %d", $order->order_id));
    if ($status == $settings['order_status']) {
      return TRUE;
    }
    return FALSE;
  }
?>

That should take care of other fringe cases or overlapping workflow configurations, right?

permalink #10 Wed, 12/19/2007 - 11:49

lutegrass

Posts: 167
Joined: 10/08/2007

That looks good. As long as you're checking the db before a status change you should be fine, I think. Smiling The only place where this could get tricky is where an order object's order_status is updated in the flow without writing it to the database. Thanks for your hard work. Ubercart has been awesome!

Christopher Schaub
LuteGrass, LLC
http://www.lutegrass.com

permalink #11 Mon, 01/21/2008 - 01:56

simonv

Posts: 8
Joined: 01/21/2008

Just wondering if there is a proper patch for this? I'm not sure that this is the exact same issue. I am trying to grant a role with the purchase. My payment gets stuck in 'payment_received' when coming back from Paypal, and even though I have the Product Features Order Status under role Assignment Settings set to Payment Received. Something is not firing to grant the role. I have to manually set the Order Status to something else and then back to 'payment_received' and then the role is granted.

permalink #12 Mon, 01/21/2008 - 11:12

Ryan

Posts: 5269
Joined: 08/07/2007

I'm not really sure where the solution would be since it's been a while... what version of Ubercart are you working on now?

permalink #13 Mon, 01/21/2008 - 12:32

simonv

Posts: 8
Joined: 01/21/2008

ubercart 5.x-1.0-alpha8

I just realized that under the recent 'ubercart 5.x-1.0-beta2' release it says "The bugs not on the list of most importance are the bugs in the roles and shipping systems that have been fixed but keep getting reported. ; )". I will install and see if I this is one of those bugs.

permalink #14 Mon, 01/21/2008 - 17:04

simonv

Posts: 8
Joined: 01/21/2008

All is well with beta2 release, thanks.

	Drupalcon DC
	Vote now to learn more about Ubercart in these sessions: Ubercart on Drupal 6 Advanced Ubercart Usage Starting Your Own Ubercart Store

	Ubercart Affiliates
	Find payment and hosting services in our Affiliate Directory that support Ubercart development.

	User login
	Username: * Password: * Create new account Request new password

	Fast Invoicing
	We use and recommend FreshBooks for project time tracking and client invoicing.

Ubercart

workflow payment status gets clobbered - stale order object - bad bug

Navigation

Drupalcon DC

Ubercart Affiliates

User login

Fast Invoicing